-
Dec 22 06:00:00 firewall1 xinetd[51686]: Starting reconfiguration Dec 22 06:00:00 firewall1 xinetd[51686]: Swapping defaults Dec 22 06:00:00 firewall1 xinetd[51686]: readjusting service 6969-udp Dec 22 06:00:00 firewall1 xinetd[51686]: Reconfigured: new=0 old=1 dropped=0 (services) Dec 22 06:01:56 firewall1 php: [pfBlockerNG] Starting cron process. Dec 22 06:05:09 firewall1 php: [pfBlockerNG] No changes to Firewall rules, skipping Filter Reload Dec 22 06:15:00 firewall1 xinetd[51686]: Starting reconfiguration Dec 22 06:15:00 firewall1 xinetd[51686]: Swapping defaults Dec 22 06:15:00 firewall1 xinetd[51686]: readjusting service 6969-udp Dec 22 06:15:00 firewall1 xinetd[51686]: Reconfigured: new=0 old=1 dropped=0 (services) Dec 22 06:21:18 firewall1 blazer_usb[5521]: Permissions problem: Input/output error Dec 22 06:21:18 firewall1 upsd[5189]: Can't connect to UPS [ActiveJet] (blazer_usb-ActiveJet): No such file or directory Dec 22 06:21:19 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:21:19 firewall1 upsmon[4542]: Communications with UPS ActiveJet lost Dec 22 06:21:19 firewall1 php-cgi: nut_email.php: Message sent to xxxxxxxxxxxxxx OK Dec 22 06:21:24 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:21:29 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:21:34 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:21:39 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:21:44 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:21:49 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:21:54 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:21:59 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:22:04 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:22:09 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:22:14 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:22:19 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:22:24 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:22:29 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:22:34 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:22:39 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:22:44 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:22:49 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:22:54 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:22:59 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:23:04 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:23:09 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:23:14 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:23:19 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:23:24 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:23:29 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:23:34 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:23:39 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:23:44 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:23:49 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:23:54 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:23:59 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:24:04 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:24:09 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:24:14 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:24:19 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:24:24 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:24:29 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:24:34 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:24:39 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:24:44 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:24:49 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:24:54 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:24:59 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:25:04 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:25:09 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:25:14 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:25:19 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:25:24 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:25:29 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:25:34 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:25:39 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:25:44 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:25:49 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:25:54 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:25:59 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:26:04 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:26:09 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:26:14 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:26:14 firewall1 upsmon[4542]: UPS ActiveJet is unavailable Dec 22 06:26:15 firewall1 php-cgi: nut_email.php: Message sent to xxxxxxxxxxxxxx OK Dec 22 06:26:18 firewall1 upsd[5189]: Can't connect to UPS [ActiveJet] (blazer_usb-ActiveJet): No such file or directory Dec 22 06:26:19 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:26:24 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 06:26:29 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected ... Dec 22 08:59:43 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 08:59:48 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 08:59:53 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected Dec 22 08:59:58 firewall1 upsmon[4542]: Poll UPS [ActiveJet] failed - Driver not connected ....usbconfig dump_device_desc
ugen0.1: <uhci root="" hub="" intel=""> at usbus0, cfg=0 md=HOST spd=FULL (12Mbps) pwr=SAVE (0mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0100 bDeviceClass = 0x0009 <hub> bDeviceSubClass = 0x0000 bDeviceProtocol = 0x0000 bMaxPacketSize0 = 0x0040 idVendor = 0x0000 idProduct = 0x0000 bcdDevice = 0x0100 iManufacturer = 0x0001 <intel> iProduct = 0x0002 <uhci root="" hub=""> iSerialNumber = 0x0000 <no string=""> bNumConfigurations = 0x0001 ugen3.1: <ehci root="" hub="" intel=""> at usbus3, cfg=0 md=HOST spd=HIGH (480Mbps) pwr=SAVE (0mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0200 bDeviceClass = 0x0009 <hub> bDeviceSubClass = 0x0000 bDeviceProtocol = 0x0001 bMaxPacketSize0 = 0x0040 idVendor = 0x0000 idProduct = 0x0000 bcdDevice = 0x0100 iManufacturer = 0x0001 <intel> iProduct = 0x0002 <ehci root="" hub=""> iSerialNumber = 0x0000 <no string=""> bNumConfigurations = 0x0001 ugen2.1: <uhci root="" hub="" intel=""> at usbus2, cfg=0 md=HOST spd=FULL (12Mbps) pwr=SAVE (0mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0100 bDeviceClass = 0x0009 <hub> bDeviceSubClass = 0x0000 bDeviceProtocol = 0x0000 bMaxPacketSize0 = 0x0040 idVendor = 0x0000 idProduct = 0x0000 bcdDevice = 0x0100 iManufacturer = 0x0001 <intel> iProduct = 0x0002 <uhci root="" hub=""> iSerialNumber = 0x0000 <no string=""> bNumConfigurations = 0x0001 ugen1.1: <uhci root="" hub="" intel=""> at usbus1, cfg=0 md=HOST spd=FULL (12Mbps) pwr=SAVE (0mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0100 bDeviceClass = 0x0009 <hub> bDeviceSubClass = 0x0000 bDeviceProtocol = 0x0000 bMaxPacketSize0 = 0x0040 idVendor = 0x0000 idProduct = 0x0000 bcdDevice = 0x0100 iManufacturer = 0x0001 <intel> iProduct = 0x0002 <uhci root="" hub=""> iSerialNumber = 0x0000 <no string=""> bNumConfigurations = 0x0001 ugen6.1: <uhci root="" hub="" intel=""> at usbus6, cfg=0 md=HOST spd=FULL (12Mbps) pwr=SAVE (0mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0100 bDeviceClass = 0x0009 <hub> bDeviceSubClass = 0x0000 bDeviceProtocol = 0x0000 bMaxPacketSize0 = 0x0040 idVendor = 0x0000 idProduct = 0x0000 bcdDevice = 0x0100 iManufacturer = 0x0001 <intel> iProduct = 0x0002 <uhci root="" hub=""> iSerialNumber = 0x0000 <no string=""> bNumConfigurations = 0x0001 ugen5.1: <uhci root="" hub="" intel=""> at usbus5, cfg=0 md=HOST spd=FULL (12Mbps) pwr=SAVE (0mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0100 bDeviceClass = 0x0009 <hub> bDeviceSubClass = 0x0000 bDeviceProtocol = 0x0000 bMaxPacketSize0 = 0x0040 idVendor = 0x0000 idProduct = 0x0000 bcdDevice = 0x0100 iManufacturer = 0x0001 <intel> iProduct = 0x0002 <uhci root="" hub=""> iSerialNumber = 0x0000 <no string=""> bNumConfigurations = 0x0001 ugen4.1: <uhci root="" hub="" intel=""> at usbus4, cfg=0 md=HOST spd=FULL (12Mbps) pwr=SAVE (0mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0100 bDeviceClass = 0x0009 <hub> bDeviceSubClass = 0x0000 bDeviceProtocol = 0x0000 bMaxPacketSize0 = 0x0040 idVendor = 0x0000 idProduct = 0x0000 bcdDevice = 0x0100 iManufacturer = 0x0001 <intel> iProduct = 0x0002 <uhci root="" hub=""> iSerialNumber = 0x0000 <no string=""> bNumConfigurations = 0x0001 ugen7.1: <ehci root="" hub="" intel=""> at usbus7, cfg=0 md=HOST spd=HIGH (480Mbps) pwr=SAVE (0mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0200 bDeviceClass = 0x0009 <hub> bDeviceSubClass = 0x0000 bDeviceProtocol = 0x0001 bMaxPacketSize0 = 0x0040 idVendor = 0x0000 idProduct = 0x0000 bcdDevice = 0x0100 iManufacturer = 0x0001 <intel> iProduct = 0x0002 <ehci root="" hub=""> iSerialNumber = 0x0000 <no string=""> bNumConfigurations = 0x0001 ugen5.2: <usb to="" serial="" inno="" tech=""> at usbus5, cfg=0 md=HOST spd=LOW (1.5Mbps) pwr=ON (100mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0110 bDeviceClass = 0x0000 <probed by="" interface="" class=""> bDeviceSubClass = 0x0000 bDeviceProtocol = 0x0000 bMaxPacketSize0 = 0x0008 idVendor = 0x0665 idProduct = 0x5161 bcdDevice = 0x0002 iManufacturer = 0x0001 <retrieving string="" failed=""> iProduct = 0x0002 <retrieving string="" failed=""> iSerialNumber = 0x0000 <no string=""> bNumConfigurations = 0x0001</no></retrieving></retrieving></probed></usb></no></ehci></intel></hub></ehci></no></uhci></intel></hub></uhci></no></uhci></intel></hub></uhci></no></uhci></intel></hub></uhci></no></uhci></intel></hub></uhci></no></uhci></intel></hub></uhci></no></ehci></intel></hub></ehci></no></uhci></intel></hub></uhci>Service restarted OK from Status-Services
Dec 22 09:07:44 upsd 20160 User monuser@127.0.0.1 logged into UPS [ActiveJet] Dec 22 09:07:44 upsd 20160 Connected to UPS [ActiveJet]: blazer_usb-ActiveJet Dec 22 09:07:43 blazer_usb 20285 Startup successful Dec 22 09:07:42 upsd 20160 Startup successful Dec 22 09:07:42 upsd 20019 Can't connect to UPS [ActiveJet] (blazer_usb-ActiveJet): No such file or directory Dec 22 09:07:42 upsd 20019 listening on 127.0.0.1 port 3493 Dec 22 09:07:42 upsd 20019 listening on ::1 port 3493 Dec 22 09:07:41 upsmon 18970 Startup successful Dec 22 09:07:41 upsd 5189 Signal 15: exiting Dec 22 09:07:41 upsd 5189 mainloop: Interrupted system call Dec 22 09:07:41 upsd 5189 User monuser@127.0.0.1 logged out from UPS [ActiveJet] Dec 22 09:07:41 upsmon 4542 Signal 15: exiting Dec 22 09:07:38 upsmon 4542 Poll UPS [ActiveJet] failed - Driver not connected Dec 22 09:07:33 upsmon 4542 Poll UPS [ActiveJet] failed - Driver not connected Dec 22 09:07:28 upsmon 4542 Poll UPS [ActiveJet] failed - Driver not connected Dec 22 09:07:23 upsmon 4542 Poll UPS [ActiveJet] failed - Driver not connected Dec 22 09:07:18 upsmon 4542 Poll UPS [ActiveJet] failed - Driver not connected Dec 22 09:07:13 upsmon 4542 Poll UPS [ActiveJet] failed - Driver not connected ...p.s.
it looks like upssched is not executed at all because it not stop the service, and this is wrong.
I need a script that will restart the UPS service, only if communication with UPS is lost and upsched is not doing this at the moment.edit
I think I understand why is not executed… normal is executed from NOTIFYCMD which now is substituted by nut_email.php... -
Dec 22 06:21:18 firewall1 blazer_usb[5521]: Permissions problem: Input/output errorPretty sure I know what the problem is. Going to take a bit of research to find out if there is a work-around.
-
Here's my analysis. Short version: You have a flakey UPS and are also encountering a kernel bug.
The UPS is using an inbuilt Cypress 1.0 USB to serial chip (vendor 0x0665 product 0x5161). What kicks the problem off is that the chip flakes out briefly. This appears to be a pretty well known issue with this chip.
When this happens at the wrong moment, it triggers a bug in the FreeBSD kernel. The kernel gets confused. It's one of those "this should never happen" bugs. When it does happen, it triggers a safety check that causes EPERM (not permitted) to be returned in response to a read or write operations on the USB device. The error value EPERM is incorrect. It should return EIO or ENXIO.
The NUT Blazer driver (or Qx driver) would correctly handle EIO or ENXIO, and attempt close/reopen the device. However the driver interprets EPERM for any USB command to be a fatal error, causing the driver to exit. One could argue that the NUT driver could be changed to treat EPERM the same as ENXIO for FreeBSD, but this would create problems with driver when there are actual permission problems. And it really isn't their bug.
I don't have a device that produces this behavior, so I cannot effectively debug the root cause of the kernel issue. The best I can do is to submit a patch to the FreeBSD folk to change the return value from the safety check, which I will do. However I expect that it will take a long time for this change to make its way into a released kernel.
In the interim, several choices come to mind:
1. Get a new UPS. Something that doesn't use the old Cypress USB chip.
2. Build a custom kernel to use with pfSense. This is a very bad idea, and I mention it for completeness only.
3. Build a custom version of the NUT Blazer driver. If you want to do this, let me know and I will send you a patch that will work around the problem. You will need a working FreeBSD 10.3 development environment to do the build.
4. Move the UPS to another host (non FreeBSD), and use NUT's remote monitoring feature from pfSense.
5. Try to work around it with scripts. This approach is fine as long as there isn't a power failure. If the problem happens in close proximity to a power failure, this may well result in failure of the shutdown function.Option #1 is your best bet. If you can't do that, then I would look at #4. I don't know what your other hosts are, but if one is a Linux box that you can run NUT on, this is a good way to go. If you cannot do #1 or #4, let me know and I can suggest an alternate approach for #5.
Sorry to not have better news to offer.
-
Concerning scripts work around it may be usb root hub device power off and power on with usbconfig.
Something similar to— turn off
usbconfig -d 0.1 set_config 255
— turn on
usbconfig -d 0.1 set_config 0
0.1 is device address on root hub, ex. ugen0.1
This should reset device connection as it happening on PC reboot.
-
Thank you for analysis.
1 - Unfortunately at this moment it is not possible; this year I bayed this UPS and can't return it any more, it have 2 years warranty but I am sure seller/manufacturer will not fix this problem. To buy another one here in Poland will be a game of chance as seller & manufacturer don't publish full spec. On log term plan I am thinking it will be better to buy an inverter.
2 - No.
3 - I can replace the driver only if you can post the driver patched as I don't have a working FreeBSD 10.3 development environment to do the build.
4 - Not possible for the moment the other computers around are win that are scheduled to turn off overnight and also I don't have a monitor program for win.
5 - Yes, for the moment I just returned to scheduled cron script that restart NUT every 15 min… any help is appreciated.thank you
p.s.
w0w unfortunately your suggestion don't work:
usbconfig -d 5.2 set_config 255 - it kill the communication but;
usbconfig -d 5.2 set_config 0 - can't restore the communication, not even NUT restart will fix it and I have to unplug the USB cable to fix the communication.ugen5.2: <usb to="" serial="" inno="" tech="">at usbus5, cfg=255 md=HOST spd=LOW (1.5Mbps) pwr=ON (100mA)
bLength = 0x0012
bDescriptorType = 0x0001
bcdUSB = 0x0110
bDeviceClass = 0x0000 <probed by="" interface="" class="">bDeviceSubClass = 0x0000
bDeviceProtocol = 0x0000
bMaxPacketSize0 = 0x0008
idVendor = 0x0665
idProduct = 0x5161
bcdDevice = 0x0002
iManufacturer = 0x0001 <retrieving string="" failed="">iProduct = 0x0002 <retrieving string="" failed="">iSerialNumber = 0x0000 <no string="">bNumConfigurations = 0x0001</no></retrieving></retrieving></probed></usb> -
I am sorry, my bad, instead of powering off and on your device just try to do this with root hub where is your ups is connected.
Do
usbconfig | grep ugen5
You should see something like
ugen5.1: <uhci root="" hub="" intel="">at usbus2, cfg=0 md=HOST spd=FULL (12Mbps) pwr=SAVE
ugen5.2: <usb to="" serial="" inno="" tech="">at usbus5, cfg=255 md=HOST spd=LOW (1.5Mbps) pwr=ON (100mA)
So try
usbconfig -d 5.1 set_config 255
usbconfig -d 5.1 set_config 0
and see what happening.</usb></uhci> -
I tested:
communication is not restored automatically after power on the USB hub, it still required to restart the NUT service.edit.
Thank you.
I like the idea to power OFF-ON the USB HUB so I added to nut_restart script:
#!/bin/sh
/usr/local/etc/rc.d/nut.sh stop
usbconfig -d 5.1 set_config 255
sleep 30
usbconfig -d 5.1 set_config 0
sleep 30
/usr/local/etc/rc.d/nut.sh start -
4 - Not possible for the moment the other computers around are win that are scheduled to turn off overnight and also I don't have a monitor program for win.
Maybe you could utilize a RPi-Linux at 3W power ?
-
Sorry I have no RPI here in Poland… and to buy now rpi3+memory+case+power here is ~90 $...
-
Instead restarting NUT in sheduled fashion, just use script below to check if upsc fails to connect ups and then restart everything you want.
When UPS driver connection is lost, run
upsc -l
It gives you your configured UPS name, run
upsc "upsname"
without quotesremember the output, you will need it below in pattern variable. Just put it in quotes like it is.
for example if upsc myhomeups gives you output
connection unavailable
then change script line topattern="connection unavailable"
#!/bin/sh # Script to restart NUT and USB UPS if UPS connection failed upsname=$(upsc -l) pattern="failed UPS message from upsc" check=$(upsc $upsname | grep -o "$pattern") if [ "$check" = "$pattern" ] ; then /usr/local/etc/rc.d/nut.sh stop usbconfig -d 5.1 set_config 255 sleep 30 usbconfig -d 5.1 set_config 0 sleep 30 /usr/local/etc/rc.d/nut.sh start fiYou can use cron to schedule script for every 3 minutes for example, or even less if you tune down your sleep timers.
-
This is what I did:
because this is normal output if communication with UPS is working OK:
upsc ActiveJet
battery.charge: 100 battery.charge.low: 50 battery.runtime: 714 battery.runtime.low: 600 battery.voltage: 13.70 battery.voltage.high: 13.7 battery.voltage.low: 12 device.type: ups driver.flag.norating: enabled driver.flag.novendor: enabled driver.name: blazer_usb driver.parameter.pollinterval: 10 driver.parameter.port: auto driver.parameter.protocol: mustek driver.parameter.runtimecal: 180,100,320,50 driver.parameter.synchronous: no driver.version: 2.7.4 driver.version.internal: 0.12 input.frequency: 50.0 input.voltage: 241.2 input.voltage.fault: 241.2 output.voltage: 241.2 ups.beeper.status: enabled ups.delay.shutdown: 30 ups.delay.start: 180 ups.load: 19 ups.productid: 5161 ups.status: OL ups.type: offline / line interactive ups.vendorid: 0665I changed your script to this one:
#!/bin/sh
Script to restart NUT and USB UPS if UPS connection failed on ActiveJet
upsname="ActiveJet"
pattern="battery.charge:"
check=$(upsc $upsname | grep -o "$pattern")
if [ "$check" != "$pattern" ]; then
/usr/local/etc/rc.d/nut.sh stopusbconfig -d 5.1 set_config 255
sleep 10
usbconfig -d 5.1 set_config 0
sleep 5
/usr/local/etc/rc.d/nut.sh start
fiand I added to cron to run it every 3 min.
If you have a better suggestion please share.
Thank you again !
edit:
changed the script and cron from 2 to 3 and now to 4 min because something is not ok and it restart to often. -
strange … If I did not made a mistake I think the script interfere with normal NUT because it will restart almost every time.
Maybe we can look in syslog for last NUT error messages and not try to interrogate NUT ??Dec 23 21:40:08 upsd 59705 User monuser@127.0.0.1 logged into UPS [ActiveJet] Dec 23 21:40:06 upsd 59705 Startup successful Dec 23 21:40:06 upsd 59382 Connected to UPS [ActiveJet]: blazer_usb-ActiveJet Dec 23 21:40:06 upsd 59382 listening on 127.0.0.1 port 3493 Dec 23 21:40:06 upsd 59382 listening on ::1 port 3493 Dec 23 21:40:05 blazer_usb 59211 Startup successful Dec 23 21:40:05 upsmon 58620 Startup successful Dec 23 21:40:00 blazer_usb 86268 Signal 15: exiting Dec 23 21:40:00 upsd 86696 Signal 15: exiting Dec 23 21:40:00 upsd 86696 mainloop: Interrupted system call Dec 23 21:40:00 upsd 86696 User monuser@127.0.0.1 logged out from UPS [ActiveJet] Dec 23 21:40:00 upsmon 86014 Signal 15: exiting Dec 23 21:36:08 upsd 86696 User monuser@127.0.0.1 logged into UPS [ActiveJet] Dec 23 21:36:06 upsd 86696 Startup successful Dec 23 21:36:06 upsd 86543 Connected to UPS [ActiveJet]: blazer_usb-ActiveJet Dec 23 21:36:06 upsd 86543 listening on 127.0.0.1 port 3493 Dec 23 21:36:06 upsd 86543 listening on ::1 port 3493 Dec 23 21:36:05 blazer_usb 86268 Startup successful Dec 23 21:36:05 upsmon 85553 Startup successful Dec 23 21:36:00 blazer_usb 8319 Signal 15: exiting Dec 23 21:36:00 upsd 8660 Signal 15: exiting Dec 23 21:36:00 upsd 8660 mainloop: Interrupted system call Dec 23 21:36:00 upsd 8660 User monuser@127.0.0.1 logged out from UPS [ActiveJet] Dec 23 21:36:00 upsmon 7932 Signal 15: exiting Dec 23 21:32:08 upsd 8660 User monuser@127.0.0.1 logged into UPS [ActiveJet] Dec 23 21:32:06 upsd 8660 Startup successful Dec 23 21:32:06 upsd 8388 Connected to UPS [ActiveJet]: blazer_usb-ActiveJet Dec 23 21:32:06 upsd 8388 listening on 127.0.0.1 port 3493 Dec 23 21:32:06 upsd 8388 listening on ::1 port 3493 Dec 23 21:32:05 blazer_usb 8319 Startup successful Dec 23 21:32:05 upsmon 7510 Startup successful Dec 23 21:32:00 upsd 33016 Signal 15: exiting Dec 23 21:32:00 upsd 33016 mainloop: Interrupted system call Dec 23 21:32:00 upsd 33016 User monuser@127.0.0.1 logged out from UPS [ActiveJet] Dec 23 21:32:00 upsmon 32741 Signal 15: exiting ... -
Remove any other scripts you have put in place and replace /usr/local/etc/rc.d/nut.sh with the script below. I would not add any USB configuration commands unless you encounter a situation in which the script does not restart the driver. If you do encounter such a situation, please run "usbconfig dump_device_desc" while the problem is happening and post the result.
Note that the nut.sh script is automatically written every time the NUT configuration is saved This will happen anytime you change the UPS config or upgrade pfSense. When this happens, just copy this script back in place.
I would keep the setting of "pollinterval = 10" in the ups.conf advanced section as this will significantly reduce the number of occurrences of driver failure. No other advanced settings are needed.
#!/bin/sh # This file has been modified for special upsdrvctl restart rc_start() { echo starting NUT if [ -f /var/run/upsdrvctl_loop.pid ] then kill -9 `cat /var/db/nut/upsdrvctl_loop.pid` rm /var/run/upsdrvctl_loop.pid fi /usr/bin/killall -q -9 upsmon /usr/bin/killall -q -9 upsd /usr/bin/killall -q -9 upsdrvctl /usr/bin/killall -q -9 blazer_usb /usr/local/sbin/upsmon /usr/local/sbin/upsdrvctl start & ( while true do sleep 15 kill -0 `cat /var/db/nut/blazer_usb-ups.pid` > /dev/null 2>&1 && continue echo "needs restart" /usr/local/sbin/upsdrvctl start done ) & echo $! > /var/db/nut/upsdrvctl_loop.pid sleep 1 /usr/local/sbin/upsd -u root return 0 } rc_stop() { echo stopping NUT if [ -f /var/db/nut/upsdrvctl_loop.pid ] then kill -9 `cat /var/db/nut/upsdrvctl_loop.pid` rm /var/db/nut/upsdrvctl_loop.pid fi /usr/bin/killall -q upsmon /usr/bin/killall -q upsd /usr/bin/killall -q upsdrvctl /usr/bin/killall -q blazer_usb return 0 } case $1 in start) rc_start ;; stop) rc_stop ;; restart) rc_stop rc_start ;; esac -
Regarding the other settings you were doing:
default.battery.voltage.high = 13.7 default.battery.voltage.low = 11.5 runtimecal = 180,100,360,50 ignorelb override.battery.charge.low = 50 override.battery.runtime.low = 600These are actually arguments to the UPS driver rather than global directives. As such, they should be in the (non-advanced) section entitled "Extra Arguments to driver" rather than in the advanced section.
You should have nothing in the advanced section other than the pollinterval setting in ups.conf.
Hope this works out for you.
-
I did what you said but it looks like the script enter in a cyclic restart:
Dec 23 23:36:51 upsd 15530 Connected to UPS [ActiveJet]: blazer_usb-ActiveJet Dec 23 23:36:50 blazer_usb 24413 Startup successful Dec 23 23:36:48 php-cgi nut_email.php: Message sent to xxxxxxxxxxx OK Dec 23 23:36:47 upsmon 14675 Communications with UPS ActiveJet lost Dec 23 23:36:47 upsmon 14675 Poll UPS [ActiveJet] failed - Driver not connected Dec 23 23:36:44 blazer_usb 55222 Signal 15: exiting Dec 23 23:36:33 php-cgi nut_email.php: Message sent to xxxxxxxxxxx OK Dec 23 23:36:32 upsmon 14675 Communications with UPS ActiveJet established Dec 23 23:36:29 upsd 15530 Connected to UPS [ActiveJet]: blazer_usb-ActiveJet Dec 23 23:36:29 blazer_usb 55222 Startup successful Dec 23 23:36:27 php-cgi nut_email.php: Message sent to xxxxxxxxxxx OK Dec 23 23:36:27 upsmon 14675 Communications with UPS ActiveJet lost Dec 23 23:36:27 upsmon 14675 Poll UPS [ActiveJet] failed - Driver not connected Dec 23 23:36:22 blazer_usb 27723 Signal 15: exiting Dec 23 23:36:12 php-cgi nut_email.php: Message sent to xxxxxxxxxxx OK Dec 23 23:36:12 upsmon 14675 Communications with UPS ActiveJet established Dec 23 23:36:09 upsd 15530 Connected to UPS [ActiveJet]: blazer_usb-ActiveJet Dec 23 23:36:07 blazer_usb 27723 Startup successful Dec 23 23:36:07 upsmon 14675 Poll UPS [ActiveJet] failed - Driver not connected Dec 23 23:36:03 php-cgi nut_email.php: Message sent to xxxxxxxxxxx OK Dec 23 23:36:02 upsmon 14675 Communications with UPS ActiveJet lost Dec 23 23:36:02 upsmon 14675 Poll UPS [ActiveJet] failed - Driver not connected Dec 23 23:36:00 blazer_usb 90201 Signal 15: exiting Dec 23 23:35:47 php-cgi nut_email.php: Message sent to xxxxxxxxxxx OK Dec 23 23:35:47 upsmon 14675 Communications with UPS ActiveJet established Dec 23 23:35:46 upsd 15530 Connected to UPS [ActiveJet]: blazer_usb-ActiveJet Dec 23 23:35:45 blazer_usb 90201 Startup successful Dec 23 23:35:43 php-cgi nut_email.php: Message sent to xxxxxxxxxxx OK Dec 23 23:35:42 upsmon 14675 Communications with UPS ActiveJet lost Dec 23 23:35:42 upsmon 14675 Poll UPS [ActiveJet] failed - Driver not connected Dec 23 23:35:39 blazer_usb 15841 Signal 15: exiting Dec 23 23:35:27 upsd 15530 User monuser@127.0.0.1 logged into UPS [ActiveJet] Dec 23 23:35:27 upsd 15530 Connected to UPS [ActiveJet]: blazer_usb-ActiveJet Dec 23 23:35:25 blazer_usb 15841 Startup successful Dec 23 23:35:25 upsd 15530 Startup successful Dec 23 23:35:25 upsd 15312 Can't connect to UPS [ActiveJet] (blazer_usb-ActiveJet): No such file or directory Dec 23 23:35:25 upsd 15312 listening on 127.0.0.1 port 3493 Dec 23 23:35:25 upsd 15312 listening on ::1 port 3493 Dec 23 23:35:24 upsmon 14123 Startup successful -
That looks like kill is missing the -0.
Just to confirm the script is correct, could you run a sum on it please?
sum /usr/local/etc/rc.d/nut.sh
The result should be 60215.
-
yes it is correct. ( I copied also to nut.sh.new in case it is recreated )
60215 2 /usr/local/etc/rc.d/nut.sh.new -
Apologies. There was a typo in the pidfile name left over from my testing (based on usbhid-ups rather than blazer_usb).
Updated version follows.
#!/bin/sh # This file has been modified for special upsdrvctl restart rc_start() { echo starting NUT if [ -f /var/run/upsdrvctl_loop.pid ] then kill -9 `cat /var/db/nut/upsdrvctl_loop.pid` rm /var/run/upsdrvctl_loop.pid fi /usr/bin/killall -q -9 upsmon /usr/bin/killall -q -9 upsd /usr/bin/killall -q -9 upsdrvctl /usr/bin/killall -q -9 blazer_usb /usr/local/sbin/upsmon /usr/local/sbin/upsdrvctl start & ( while true do sleep 15 kill -0 `cat /var/db/nut/blazer_usb.pid` > /dev/null 2>&1 && continue /usr/local/sbin/upsdrvctl start done ) & echo $! > /var/db/nut/upsdrvctl_loop.pid sleep 1 /usr/local/sbin/upsd -u root return 0 } rc_stop() { echo stopping NUT if [ -f /var/db/nut/upsdrvctl_loop.pid ] then kill -9 `cat /var/db/nut/upsdrvctl_loop.pid` rm /var/db/nut/upsdrvctl_loop.pid fi /usr/bin/killall -q upsmon /usr/bin/killall -q upsd /usr/bin/killall -q upsdrvctl /usr/bin/killall -q blazer_usb return 0 } case $1 in start) rc_start ;; stop) rc_stop ;; restart) rc_stop rc_start ;; esac -
strange … If I did not made a mistake I think the script interfere with normal NUT because it will restart almost every time.
#!/bin/sh # Script to restart NUT and USB UPS if UPS connection failed upsname=$(upsc -l) pattern="battery.charge:" check=$(upsc $upsname | grep -o "$pattern") if [ "$check" != "$pattern" ]; then echo "("$check" != "$pattern"), NUT must be restarted" else echo ""$pattern" found, NUT is running and OK" fiFor me even if I change upsname=$(upsc -l) directly to ups name it works just fine and NEVER gives me message "NUT must be restarted". If your UPS does not answer to every query, then it is the root cause of the script behavior. You should manually test script, running this several times, looking for the answer.
-
Apologies. There was a typo in the pidfile name left over from my testing (based on usbhid-ups rather than blazer_usb).
Updated version follows.
….....9960 2 /usr/local/etc/rc.d/nut.shNew update it have the same behavior… restarting.
Dec 24 07:37:26 blazer_usb 32252 Signal 15: exiting Dec 24 07:37:26 upsd 26542 Signal 15: exiting Dec 24 07:37:26 upsd 26542 mainloop: Interrupted system call Dec 24 07:37:26 upsd 26542 User monuser@127.0.0.1 logged out from UPS [ActiveJet] Dec 24 07:37:26 upsmon 25058 Signal 15: exiting Dec 24 07:37:20 php-cgi nut_email.php: Message sent to xxxxxxxxxxxxxx OK Dec 24 07:37:20 upsmon 25058 Communications with UPS ActiveJet established Dec 24 07:37:17 upsd 26542 Connected to UPS [ActiveJet]: blazer_usb-ActiveJet Dec 24 07:37:15 blazer_usb 32252 Startup successful Dec 24 07:37:15 upsmon 25058 Poll UPS [ActiveJet] failed - Driver not connected Dec 24 07:37:10 php-cgi nut_email.php: Message sent to xxxxxxxxxxxxxx OK Dec 24 07:37:10 upsmon 25058 Communications with UPS ActiveJet lost Dec 24 07:37:10 upsmon 25058 Poll UPS [ActiveJet] failed - Driver not connected Dec 24 07:37:08 blazer_usb 60207 Signal 15: exiting Dec 24 07:37:00 php-cgi nut_email.php: Message sent to xxxxxxxxxxxxxx OK Dec 24 07:37:00 upsmon 25058 Communications with UPS ActiveJet established Dec 24 07:36:55 upsd 26542 Connected to UPS [ActiveJet]: blazer_usb-ActiveJet Dec 24 07:36:55 upsmon 25058 Poll UPS [ActiveJet] failed - Driver not connected Dec 24 07:36:53 blazer_usb 60207 Startup successful Dec 24 07:36:50 php-cgi nut_email.php: Message sent to xxxxxxxxxxxxxx OK Dec 24 07:36:50 upsmon 25058 Communications with UPS ActiveJet lost Dec 24 07:36:50 upsmon 25058 Poll UPS [ActiveJet] failed - Driver not connected Dec 24 07:36:47 blazer_usb 26864 Signal 15: exiting Dec 24 07:36:35 upsd 26542 User monuser@127.0.0.1 logged into UPS [ActiveJet] Dec 24 07:36:35 upsd 26542 Connected to UPS [ActiveJet]: blazer_usb-ActiveJet Dec 24 07:36:33 blazer_usb 26864 Startup successful Dec 24 07:36:33 upsd 26542 Startup successful Dec 24 07:36:33 upsd 26332 Can't connect to UPS [ActiveJet] (blazer_usb-ActiveJet): No such file or directory Dec 24 07:36:33 upsd 26332 listening on 127.0.0.1 port 3493 Dec 24 07:36:33 upsd 26332 listening on ::1 port 3493 Dec 24 07:36:32 upsmon 24793 Startup successfuledit:
only pid I have in /var/db/nut:
blazer_usb-ActiveJet.pid
upsmon.pid
upsd.pidI try to use script with blazer_usb-ActiveJet.pid
edit2:
now it looks ok, will see in time how is doing.
thank you.
