NUT package (2.8.0 and below)

dennypage

@kevindd992002 said in NUT package:

I have yet to test this with my other working UPS but with the problematic UPS I also get this:

So I get input voltage out of range even though the input is around 228V now, both in the UPS display and using a voltmeter. So what gives? It looks like the UPS is transferring to battery even though it shouldn't?

This in and of itself isn't problematic. Many of the UPSs I've worked with save the last reason state in perpetuity. This just means that it happened sometime in the past.

dennypage

@kevindd992002 said in NUT package:

Jun 14 19:10:15 upsmon 40927 UPS ups battery is low

There are messaging in the log... but the timestamps don't match what you had for email. If you still have the emails, check in the body of the message for the timestamp as viewed by the pfSense box when the even happened.

As to the Synology, there probably isn't enough time for it to shutdown. See the conversation with @tman222 above about HOSTSYNC.

kevindd992002

@dennypage said in NUT package:

@kevindd992002 said in NUT package:

I have yet to test this with my other working UPS but with the problematic UPS I also get this:

So I get input voltage out of range even though the input is around 228V now, both in the UPS display and using a voltmeter. So what gives? It looks like the UPS is transferring to battery even though it shouldn't?

This in and of itself isn't problematic. Many of the UPSs I've worked with save the last reason state in perpetuity. This just means that it happened sometime in the past.

Ok, that makes sense. But if it was the battery that's causing the problem, why would it show 100% charge and yet still give me a battery low message? Cosmetics issue perhaps?

@dennypage said in NUT package:

@kevindd992002 said in NUT package:

Jun 14 19:10:15 upsmon 40927 UPS ups battery is low

There are messaging in the log... but the timestamps don't match what you had for email. If you still have the emails, check in the body of the message for the timestamp as viewed by the pfSense box when the even happened.

As to the Synology, there probably isn't enough time for it to shutdown. See the conversation with @tman222 above about HOSTSYNC.

I should've said, the timestamp I gave you were the timestamps in the body of the emails, not the email timestamps themselves. And yes, there are messaging logs like you pointed out and I did receive separate (earlier) emails for those. For some reason, I cannot find the latest messaging logs for the events that I'm referring to but I did get email notifications about them.

As for the Synology issue, well it was shutting down and waking up correctly for the past few months until recently when this whole issue started. Could that still be because of HOSTSYNC? Also, you'd have to consider that I didn't see a message log saying that an auto shutdown was initiated at all. So naturally, the Synology NAS was not given the message to shut itself down. Here's another snippet of the logs showing more:

Jun 14 18:55:20 	upsmon 	40927 	UPS ups on battery
Jun 14 19:07:23 	upsmon 	40927 	UPS ups on line power
Jun 14 19:07:33 	upsmon 	40927 	UPS ups on battery
Jun 14 19:10:15 	upsmon 	40927 	UPS ups battery is low
Jun 14 19:10:15 	upsd 	58260 	Client local-monitor@::1 set FSD on UPS [ups]
Jun 14 19:10:15 	upsmon 	40927 	Executing automatic power-fail shutdown
Jun 14 19:10:15 	upsmon 	40927 	Auto logout and shutdown proceeding
Jun 14 20:10:54 	upsmon 	33616 	Startup successful
Jun 14 20:10:53 	usbhid-ups 	54715 	Startup successful
Jun 14 20:10:53 	upsd 	78154 	listening on 192.168.55.1 port 3493
Jun 14 20:10:53 	upsd 	78154 	listening on 192.168.10.1 port 3493
Jun 14 20:10:53 	upsd 	78154 	listening on ::1 port 3493
Jun 14 20:10:53 	upsd 	78154 	listening on 127.0.0.1 port 3493
Jun 14 20:10:53 	upsd 	78154 	Connected to UPS [ups]: usbhid-ups-ups
Jun 14 20:10:53 	upsd 	78876 	Startup successful
Jun 14 20:10:55 	upsmon 	74846 	Startup successful
Jun 14 20:10:56 	usbhid-ups 	5320 	Startup successful
Jun 14 20:10:56 	upsd 	24337 	listening on 192.168.55.1 port 3493
Jun 14 20:10:56 	upsd 	24337 	listening on 192.168.10.1 port 3493
Jun 14 20:10:56 	upsd 	24337 	listening on ::1 port 3493
Jun 14 20:10:56 	upsd 	24337 	listening on 127.0.0.1 port 3493
Jun 14 20:10:56 	upsd 	24337 	Connected to UPS [ups]: usbhid-ups-ups
Jun 14 20:10:56 	upsd 	25161 	Startup successful
Jun 14 20:10:58 	upsd 	25161 	User local-monitor@::1 logged into UPS [ups]
Jun 14 20:11:17 	upsmon 	75804 	Signal 15: exiting
Jun 14 20:11:17 	upsd 	25161 	User local-monitor@::1 logged out from UPS [ups]
Jun 14 20:11:17 	upsd 	25161 	mainloop: Interrupted system call
Jun 14 20:11:17 	upsd 	25161 	Signal 15: exiting
Jun 14 20:11:17 	usbhid-ups 	5320 	Signal 15: exiting
Jun 14 20:11:17 	upsmon 	86305 	Startup successful
Jun 14 20:11:18 	usbhid-ups 	15003 	Startup successful
Jun 14 20:11:18 	upsd 	31254 	listening on 192.168.55.1 port 3493
Jun 14 20:11:18 	upsd 	31254 	listening on 192.168.10.1 port 3493
Jun 14 20:11:18 	upsd 	31254 	listening on ::1 port 3493
Jun 14 20:11:18 	upsd 	31254 	listening on 127.0.0.1 port 3493
Jun 14 20:11:18 	upsd 	31254 	Connected to UPS [ups]: usbhid-ups-ups
Jun 14 20:11:18 	upsd 	32645 	Startup successful
Jun 14 20:11:20 	upsmon 	7910 	Startup successful
Jun 14 20:11:21 	usbhid-ups 	17613 	Startup successful
Jun 14 20:11:21 	upsd 	24874 	listening on 192.168.55.1 port 3493
Jun 14 20:11:21 	upsd 	24874 	listening on 192.168.10.1 port 3493
Jun 14 20:11:21 	upsd 	24874 	listening on ::1 port 3493
Jun 14 20:11:21 	upsd 	24874 	listening on 127.0.0.1 port 3493
Jun 14 20:11:21 	upsd 	24874 	Connected to UPS [ups]: usbhid-ups-ups
Jun 14 20:11:21 	upsd 	25175 	Startup successful
Jun 14 20:11:23 	upsd 	25175 	User local-monitor@::1 logged into UPS [ups]
Jun 14 20:11:24 	upsmon 	8776 	Signal 15: exiting
Jun 14 20:11:24 	upsd 	25175 	User local-monitor@::1 logged out from UPS [ups]
Jun 14 20:11:24 	upsd 	25175 	mainloop: Interrupted system call
Jun 14 20:11:24 	upsd 	25175 	Signal 15: exiting
Jun 14 20:11:24 	usbhid-ups 	17613 	Signal 15: exiting
Jun 14 20:11:24 	upsmon 	85759 	Startup successful
Jun 14 20:11:25 	usbhid-ups 	90634 	Startup successful
Jun 14 20:11:25 	upsd 	93544 	listening on 192.168.55.1 port 3493
Jun 14 20:11:25 	upsd 	93544 	listening on 192.168.10.1 port 3493
Jun 14 20:11:25 	upsd 	93544 	listening on ::1 port 3493
Jun 14 20:11:25 	upsd 	93544 	listening on 127.0.0.1 port 3493
Jun 14 20:11:25 	upsd 	93544 	Connected to UPS [ups]: usbhid-ups-ups
Jun 14 20:11:25 	upsd 	93726 	Startup successful
Jun 14 20:11:27 	upsmon 	54332 	Startup successful
Jun 14 20:11:28 	usbhid-ups 	82393 	Startup successful
Jun 14 20:11:28 	upsd 	84598 	listening on 192.168.55.1 port 3493
Jun 14 20:11:28 	upsd 	84598 	listening on 192.168.10.1 port 3493
Jun 14 20:11:28 	upsd 	84598 	listening on ::1 port 3493
Jun 14 20:11:28 	upsd 	84598 	listening on 127.0.0.1 port 3493
Jun 14 20:11:28 	upsd 	84598 	Connected to UPS [ups]: usbhid-ups-ups
Jun 14 20:11:28 	upsd 	84882 	Startup successful
Jun 14 20:11:30 	upsd 	84882 	User local-monitor@127.0.0.1 logged into UPS [ups]
Jun 14 20:11:30 	upsmon 	55413 	upsmon parent process died - shutdown impossible
Jun 14 20:11:30 	upsmon 	55413 	Parent died - shutdown impossible
Jun 14 20:11:30 	upsd 	84882 	mainloop: Interrupted system call
Jun 14 20:11:30 	upsd 	84882 	Signal 15: exiting
Jun 14 20:11:30 	usbhid-ups 	82393 	Signal 15: exiting
Jun 14 20:11:30 	upsmon 	50205 	Startup successful
Jun 14 20:11:31 	usbhid-ups 	96450 	Startup successful
Jun 14 20:11:31 	upsd 	12323 	listening on 192.168.55.1 port 3493
Jun 14 20:11:31 	upsd 	12323 	listening on 192.168.10.1 port 3493
Jun 14 20:11:31 	upsd 	12323 	listening on ::1 port 3493
Jun 14 20:11:31 	upsd 	12323 	listening on 127.0.0.1 port 3493
Jun 14 20:11:31 	upsd 	12323 	Connected to UPS [ups]: usbhid-ups-ups
Jun 14 20:11:31 	upsd 	13583 	Startup successful
Jun 14 20:11:33 	upsd 	13583 	User local-monitor@::1 logged into UPS [ups]
Jun 14 20:11:33 	upsmon 	23508 	Startup successful
Jun 14 20:11:34 	usbhid-ups 	29129 	Startup successful
Jun 14 20:11:34 	upsd 	50344 	listening on 192.168.55.1 port 3493
Jun 14 20:11:34 	upsd 	50344 	listening on 192.168.10.1 port 3493
Jun 14 20:11:34 	upsd 	50344 	listening on ::1 port 3493
Jun 14 20:11:34 	upsd 	50344 	listening on 127.0.0.1 port 3493
Jun 14 20:11:34 	upsd 	50344 	Connected to UPS [ups]: usbhid-ups-ups
Jun 14 20:11:34 	upsd 	52255 	Startup successful
Jun 14 20:11:36 	upsd 	52255 	User local-monitor@::1 logged into UPS [ups]
Jun 14 20:11:37 	upsmon 	23951 	Signal 15: exiting
Jun 14 20:11:37 	upsd 	52255 	User local-monitor@::1 logged out from UPS [ups]
Jun 14 20:11:37 	upsd 	52255 	mainloop: Interrupted system call
Jun 14 20:11:37 	upsd 	52255 	Signal 15: exiting
Jun 14 20:11:37 	usbhid-ups 	29129 	Signal 15: exiting
Jun 14 20:11:37 	upsmon 	55886 	Startup successful
Jun 14 20:11:38 	usbhid-ups 	64728 	Startup successful
Jun 14 20:11:39 	upsd 	65039 	listening on 192.168.55.1 port 3493
Jun 14 20:11:39 	upsd 	65039 	listening on 192.168.10.1 port 3493
Jun 14 20:11:39 	upsd 	65039 	listening on ::1 port 3493
Jun 14 20:11:39 	upsd 	65039 	listening on 127.0.0.1 port 3493
Jun 14 20:11:39 	upsd 	65039 	Connected to UPS [ups]: usbhid-ups-ups
Jun 14 20:11:39 	upsd 	65095 	Startup successful
Jun 14 20:11:40 	upsd 	65095 	User local-monitor@::1 logged into UPS [ups]
Jun 14 20:11:41 	upsmon 	72255 	Startup successful
Jun 14 20:11:41 	usbhid-ups 	74310 	Startup successful
Jun 14 20:11:42 	upsd 	75747 	listening on 192.168.55.1 port 3493
Jun 14 20:11:42 	upsd 	75747 	listening on 192.168.10.1 port 3493
Jun 14 20:11:42 	upsd 	75747 	listening on ::1 port 3493
Jun 14 20:11:42 	upsd 	75747 	listening on 127.0.0.1 port 3493
Jun 14 20:11:42 	upsd 	75747 	Connected to UPS [ups]: usbhid-ups-ups
Jun 14 20:11:42 	upsd 	75891 	Startup successful
Jun 14 20:11:44 	upsd 	75891 	User local-monitor@::1 logged into UPS [ups]
Jun 14 20:26:07 	upsmon 	73025 	UPS ups on battery
Jun 14 20:26:17 	upsmon 	73025 	UPS ups on line power
Jun 15 13:14:07 	upsmon 	57800 	Startup successful
Jun 15 13:14:07 	usbhid-ups 	59029 	Startup successful
Jun 15 13:14:06 	upsd 	70280 	listening on 192.168.55.1 port 3493
Jun 15 13:14:06 	upsd 	70280 	listening on 192.168.10.1 port 3493
Jun 15 13:14:06 	upsd 	70280 	listening on ::1 port 3493
Jun 15 13:14:06 	upsd 	70280 	listening on 127.0.0.1 port 3493
Jun 15 13:14:06 	upsd 	70280 	Connected to UPS [ups]: usbhid-ups-ups
Jun 15 13:14:06 	upsd 	70814 	Startup successful
Jun 15 13:14:08 	upsmon 	55711 	Startup successful
Jun 15 13:14:09 	usbhid-ups 	85269 	Startup successful
Jun 15 13:14:10 	upsd 	99152 	listening on 192.168.55.1 port 3493
Jun 15 13:14:10 	upsd 	99152 	listening on 192.168.10.1 port 3493
Jun 15 13:14:10 	upsd 	99152 	listening on ::1 port 3493
Jun 15 13:14:10 	upsd 	99152 	listening on 127.0.0.1 port 3493
Jun 15 13:14:10 	upsd 	99152 	Connected to UPS [ups]: usbhid-ups-ups
Jun 15 13:14:10 	upsd 	99790 	Startup successful
Jun 15 13:14:12 	upsd 	99790 	User local-monitor@::1 logged into UPS [ups]
Jun 15 13:14:26 	upsmon 	55752 	Signal 15: exiting
Jun 15 13:14:26 	upsd 	99790 	User local-monitor@::1 logged out from UPS [ups]
Jun 15 13:14:26 	upsd 	99790 	mainloop: Interrupted system call
Jun 15 13:14:26 	upsd 	99790 	Signal 15: exiting
Jun 15 13:14:26 	usbhid-ups 	85269 	Signal 15: exiting
Jun 15 13:14:27 	upsmon 	4336 	Startup successful
Jun 15 13:14:27 	usbhid-ups 	12301 	Startup successful
Jun 15 13:14:28 	upsd 	12824 	listening on 192.168.55.1 port 3493
Jun 15 13:14:28 	upsd 	12824 	listening on 192.168.10.1 port 3493
Jun 15 13:14:28 	upsd 	12824 	listening on ::1 port 3493
Jun 15 13:14:28 	upsd 	12824 	listening on 127.0.0.1 port 3493
Jun 15 13:14:28 	upsd 	12824 	Connected to UPS [ups]: usbhid-ups-ups
Jun 15 13:14:28 	upsd 	12827 	Startup successful
Jun 15 13:14:30 	upsd 	12827 	User local-monitor@::1 logged into UPS [ups]
Jun 15 13:14:30 	upsmon 	20757 	Startup successful
Jun 15 13:14:30 	usbhid-ups 	23572 	Startup successful
Jun 15 13:14:31 	upsd 	24418 	listening on 192.168.55.1 port 3493
Jun 15 13:14:31 	upsd 	24418 	listening on 192.168.10.1 port 3493
Jun 15 13:14:31 	upsd 	24418 	listening on ::1 port 3493
Jun 15 13:14:31 	upsd 	24418 	listening on 127.0.0.1 port 3493
Jun 15 13:14:31 	upsd 	24418 	Connected to UPS [ups]: usbhid-ups-ups
Jun 15 13:14:31 	upsd 	24437 	Startup successful
Jun 15 13:14:33 	upsd 	24437 	User local-monitor@::1 logged into UPS [ups]
Jun 15 13:14:54 	upsmon 	22016 	Signal 15: exiting
Jun 15 13:14:54 	upsd 	24437 	User local-monitor@::1 logged out from UPS [ups]
Jun 15 13:14:54 	upsd 	24437 	mainloop: Interrupted system call
Jun 15 13:14:54 	upsd 	24437 	Signal 15: exiting
Jun 15 13:14:54 	usbhid-ups 	23572 	Signal 15: exiting
Jun 15 13:14:55 	upsmon 	70818 	Startup successful
Jun 15 13:14:55 	usbhid-ups 	72602 	Startup successful
Jun 15 13:14:56 	upsd 	74194 	listening on 192.168.55.1 port 3493
Jun 15 13:14:56 	upsd 	74194 	listening on 192.168.10.1 port 3493
Jun 15 13:14:56 	upsd 	74194 	listening on ::1 port 3493
Jun 15 13:14:56 	upsd 	74194 	listening on 127.0.0.1 port 3493
Jun 15 13:14:56 	upsd 	74194 	Connected to UPS [ups]: usbhid-ups-ups
Jun 15 13:14:56 	upsd 	74325 	Startup successful
Jun 15 13:14:58 	upsd 	74325 	User local-monitor@::1 logged into UPS [ups]
Jun 15 13:14:58 	upsmon 	87512 	Startup successful
Jun 15 13:14:58 	usbhid-ups 	90187 	Startup successful
Jun 15 13:14:59 	upsd 	90516 	listening on 192.168.55.1 port 3493
Jun 15 13:14:59 	upsd 	90516 	listening on 192.168.10.1 port 3493
Jun 15 13:14:59 	upsd 	90516 	listening on ::1 port 3493
Jun 15 13:14:59 	upsd 	90516 	listening on 127.0.0.1 port 3493
Jun 15 13:14:59 	upsd 	90516 	Connected to UPS [ups]: usbhid-ups-ups
Jun 15 13:14:59 	upsd 	90761 	Startup successful
Jun 15 13:15:01 	upsd 	90761 	User local-monitor@::1 logged into UPS [ups]
Jun 15 18:25:18 	upsmon 	88045 	Signal 15: exiting
Jun 15 18:25:18 	upsd 	90761 	User local-monitor@::1 logged out from UPS [ups]
Jun 15 18:25:18 	upsd 	90761 	mainloop: Interrupted system call
Jun 15 18:25:18 	upsd 	90761 	Signal 15: exiting
Jun 15 18:25:18 	upsmon 	60536 	Startup successful
Jun 15 18:25:19 	usbhid-ups 	62298 	Startup successful
Jun 15 18:25:20 	upsd 	62515 	listening on 192.168.55.1 port 3493
Jun 15 18:25:20 	upsd 	62515 	listening on 192.168.10.1 port 3493
Jun 15 18:25:20 	upsd 	62515 	listening on ::1 port 3493
Jun 15 18:25:20 	upsd 	62515 	listening on 127.0.0.1 port 3493
Jun 15 18:25:20 	upsd 	62515 	Connected to UPS [ups]: usbhid-ups-ups
Jun 15 18:25:20 	upsd 	62558 	Startup successful
Jun 15 18:25:21 	upsd 	62558 	User local-monitor@::1 logged into UPS [ups]

You can see that I had an auto shutdown even occur here:

Jun 14 19:10:15 	upsmon 	40927 	Executing automatic power-fail shutdown
Jun 14 19:10:15 	upsmon 	40927 	Auto logout and shutdown proceeding

But I didn't get those logs for the June 15 event that I'm talking about.

dennypage

@kevindd992002 said in NUT package:

Jun 14 18:55:20 upsmon 40927 UPS ups on battery
Jun 14 19:07:23 upsmon 40927 UPS ups on line power
Jun 14 19:07:33 upsmon 40927 UPS ups on battery
Jun 14 19:10:15 upsmon 40927 UPS ups battery is low

Also possible that the UPS killed the mains before shutdown completed. You may want to up the battery runtime/charge low values.

You definitely want to have a higher HOSTSYNC to give the Synology time for shutdown.

kevindd992002

@dennypage said in NUT package:

@kevindd992002 said in NUT package:

Jun 14 18:55:20 upsmon 40927 UPS ups on battery
Jun 14 19:07:23 upsmon 40927 UPS ups on line power
Jun 14 19:07:33 upsmon 40927 UPS ups on battery
Jun 14 19:10:15 upsmon 40927 UPS ups battery is low

Also possible that the UPS killed the mains before shutdown completed. You may want to up the battery runtime/charge low values.

You definitely want to have a higher HOSTSYNC to give the Synology time for shutdown.

Regardless though, shouldn't I see an auto shutdown message when NUT reaches the cutoff charge level?

So 120 for HOSTSYNC would be recommended for Synology? What does that parameter really do anyway?

dennypage

@kevindd992002 said in NUT package:

Regardless though, shouldn't I see an auto shutdown message when NUT reaches the cutoff charge level?

It shows a low battery situation, but the UPS could have cut the mains before pfSense had opportunity to perform a shutdown. Was the battery depleted from a prior event perhaps?

So 120 for HOSTSYNC would be recommended for Synology? What does that parameter really do anyway?

HOSTSYNC is how many seconds the master will wait for slaves to initiate their shutdown and disconnect from the master. See the documentation for upsmon.conf for more information.

kevindd992002

@dennypage said in NUT package:

@kevindd992002 said in NUT package:

Regardless though, shouldn't I see an auto shutdown message when NUT reaches the cutoff charge level?

It shows a low battery situation, but the UPS could have cut the mains before pfSense had opportunity to perform a shutdown. Was the battery depleted from a prior event perhaps?

So 120 for HOSTSYNC would be recommended for Synology? What does that parameter really do anyway?

HOSTSYNC is how many seconds the master will wait for slaves to initiate their shutdown and disconnect from the master. See the documentation for upsmon.conf for more information.

What do you mean by "it shows a low battery situation"? I don't see that in the June 15 logs. Sorry I'm confused. The UPS started charging (on online power) since June 14 8:26PM so I'm pretty sure it's fully charged by the it notified me via email on June 15 12:00PM. I also asked my relatives which are on-site and they confirmed that electricity only went out once on June 15.

dennypage

@kevindd992002 said in NUT package:

What do you mean by "it shows a low battery situation"? I don't see that in the June 15 logs. Sorry I'm confused. The UPS started charging (on online power) since June 14 8:26PM so I'm pretty sure it's fully charged by the it notified me via email on June 15 12:00PM. I also asked my relatives which are on-site and they confirmed that electricity only went out once on June 15.

Sorry, was reading low battery situation on the 14th.

Most likely guess regarding the 15th is that the UPS failed the mains before the system properly flushed the disk log.

Things I would suggest:

If the battery is over three years old, replace it.
If the battery has been through two hundred discharge cycles or more, replace it.
Perform a battery health check (long self test).
Perform a run-time calibration (note this counts as a cycle).
Raise the values for charge.low and runtime.low.

If power outages are common, I would go very high on charge.low (50 or more). Remember that regardless of age, a battery will only last 200 discharge cycles or so, so the higher you set the value the longer your battery will last.

kevindd992002

@dennypage said in NUT package:

@kevindd992002 said in NUT package:

What do you mean by "it shows a low battery situation"? I don't see that in the June 15 logs. Sorry I'm confused. The UPS started charging (on online power) since June 14 8:26PM so I'm pretty sure it's fully charged by the it notified me via email on June 15 12:00PM. I also asked my relatives which are on-site and they confirmed that electricity only went out once on June 15.

Sorry, was reading low battery situation on the 14th.

Most likely guess regarding the 15th is that the UPS failed the mains before the system properly flushed the disk log.

Things I would suggest:

If the battery is over three years old, replace it.

If the battery has been through two hundred discharge cycles or more, replace it.

Perform a battery health check (long self test).

Perform a run-time calibration (note this counts as a cycle).

Raise the values for charge.low and runtime.low.

If power outages are common, I would go very high on charge.low (50 or more). Remember that regardless of age, a battery will only last 200 discharge cycles or so, so the higher you set the value the longer your battery will last.

The battery is less than a year old and I doubt it had already gone to two hundred discharge cycles. The power outages are more frequent than what I would like them to be, yes, but not very frequent to render the batteries useless in less than a year. But yeah, I'll probably do some tests first by changing the charge.low and runtime.low. I had multiple notifications again these past few days and I'm still encountering the same issue. Here's another example of my pfsense logs:

Jun 16 16:24:38 	upsd 	19563 	User local-monitor@::1 logged into UPS [ups]
Jun 16 16:25:33 	upsd 	19563 	User local-monitor@::1 logged out from UPS [ups]
Jun 16 16:28:35 	kernel 		ugen0.2: <American Power Conversion Back-UPS RS 1500G FW878.L4 .I USB FWL4> at usbus0
Jun 16 16:29:05 	upsd 	58612 	Connected to UPS [ups]: usbhid-ups-ups
Jun 16 16:29:08 	upsd 	60154 	Connected to UPS [ups]: usbhid-ups-ups
Jun 16 16:29:10 	upsd 	61918 	User local-monitor@::1 logged into UPS [ups]
Jun 16 16:29:24 	upsd 	61918 	User local-monitor@::1 logged out from UPS [ups]
Jun 16 16:29:25 	upsd 	61474 	Connected to UPS [ups]: usbhid-ups-ups
Jun 16 16:29:28 	upsd 	73800 	Connected to UPS [ups]: usbhid-ups-ups
Jun 16 16:29:30 	upsd 	74128 	User local-monitor@::1 logged into UPS [ups]
Jun 16 16:29:55 	upsd 	74128 	User local-monitor@::1 logged out from UPS [ups]
Jun 16 16:29:56 	upsd 	24686 	Connected to UPS [ups]: usbhid-ups-ups
Jun 16 16:29:59 	upsd 	39315 	Connected to UPS [ups]: usbhid-ups-ups
Jun 16 16:30:01 	upsd 	39480 	User local-monitor@::1 logged into UPS [ups]
Jun 22 11:00:26 	upsmon 	37375 	UPS ups on battery
Jun 22 11:00:31 	upsmon 	37375 	UPS ups on line power
Jun 22 17:03:06 	upsmon 	37375 	UPS ups on battery
Jun 22 17:03:16 	upsmon 	37375 	UPS ups on line power
Jun 22 17:43:38 	upsmon 	37375 	UPS ups on battery
Jun 22 17:43:43 	upsmon 	37375 	UPS ups on line power
Jun 23 09:09:32 	upsmon 	37375 	UPS ups on battery
Jun 23 09:28:27 	upsmon 	37375 	UPS ups battery is low
Jun 23 09:28:27 	upsd 	39480 	Client local-monitor@::1 set FSD on UPS [ups]
Jun 23 12:48:03 	kernel 		ugen0.2: <American Power Conversion Back-UPS RS 1500G FW878.L4 .I USB FWL4> at usbus0
Jun 23 12:48:28 	upsd 	80605 	Connected to UPS [ups]: usbhid-ups-ups
Jun 23 12:48:31 	upsd 	62181 	Connected to UPS [ups]: usbhid-ups-ups
Jun 23 12:48:33 	upsd 	63842 	User local-monitor@::1 logged into UPS [ups]
Jun 23 12:48:50 	upsd 	63842 	User local-monitor@::1 logged out from UPS [ups]
Jun 23 12:48:51 	upsd 	6953 	Connected to UPS [ups]: usbhid-ups-ups
Jun 23 12:48:54 	upsd 	29664 	Connected to UPS [ups]: usbhid-ups-ups
Jun 23 12:48:56 	upsd 	32261 	User local-monitor@::1 logged into UPS [ups]
Jun 23 12:49:01 	upsd 	32261 	User local-monitor@::1 logged out from UPS [ups]
Jun 23 12:49:02 	upsd 	99676 	Connected to UPS [ups]: usbhid-ups-ups
Jun 23 12:49:05 	upsd 	51055 	Connected to UPS [ups]: usbhid-ups-ups
Jun 23 12:49:06 	upsd 	52551 	User local-monitor@127.0.0.1 logged into UPS [ups]
Jun 23 12:49:06 	upsmon 	40995 	upsmon parent process died - shutdown impossible
Jun 23 12:49:07 	upsd 	3258 	Connected to UPS [ups]: usbhid-ups-ups
Jun 23 12:49:10 	upsd 	10461 	Connected to UPS [ups]: usbhid-ups-ups
Jun 23 12:49:11 	upsd 	11087 	User local-monitor@127.0.0.1 logged into UPS [ups]
Jun 23 12:49:11 	upsmon 	59547 	upsmon parent process died - shutdown impossible
Jun 23 12:49:12 	upsd 	6285 	Connected to UPS [ups]: usbhid-ups-ups
Jun 23 12:49:15 	upsd 	50671 	Connected to UPS [ups]: usbhid-ups-ups
Jun 23 12:49:17 	upsd 	50757 	User local-monitor@::1 logged into UPS [ups]
Jun 23 12:49:18 	upsd 	50757 	User local-monitor@::1 logged out from UPS [ups]
Jun 23 12:49:19 	upsd 	74517 	Connected to UPS [ups]: usbhid-ups-ups
Jun 23 12:49:21 	upsd 	74650 	User local-monitor@::1 logged into UPS [ups]
Jun 23 12:49:22 	upsd 	1480 	Connected to UPS [ups]: usbhid-ups-ups
Jun 23 12:49:24 	upsd 	2139 	User local-monitor@::1 logged into UPS [ups]
Jun 23 13:09:43 	upsmon 	81543 	UPS ups on battery
Jun 23 13:09:48 	upsmon 	81543 	UPS ups on line power

Then I receive this in my email:

Sun, 23 Jun 2019 09:28:28 +0800

Auto logout and shutdown proceeding

But in the Synology NAS logs, I see an improper shutdown event for this time. So something's not right because the NAS is not shutting down properly even though I have HOSTSYNC set to 120 already.

Also, is it normal that I can't find any logs for the monuser client (the Synology NAS) connecting and disconnecting to the pfsense NUT master? I see logs like that when a Windows machine NUT service is connecting to pfsense master but not when a Synology NAS does it. Don't get me wrong though, the Synology NAS connects to it just fine and shuts down properly until today, but I never got the monuser logs.

EDIT:

Look at my Synology logs:

So it's interesting that I no longer see a Power supply event that the ups entered battery mode/returned to AC mode/etc. This explains why the NAS isn't shutting down properly. It's not receiving the appropriate signals from the NUT master even though I completely see it connected in the "Device Information" section like so:

What other things can I do to troubleshoot this then?

kevindd992002

@dennypage

Any other ideas to try?

dennypage

@kevindd992002 Sorry, I'm getting ready for a long distance move and haven't had much time lately.

The lack of entries in the pfSense system log regarding the remote client would indicate that the Synology isn't actually connecting to upsd on pfSense. You can do a reboot on your Synology to confirm. You should see log out/in messages in the pfSense system log each time.

Another way to confirm... stop the ups service on pfSense. The Synology should get upset and start sending emails complaining that the ups isn't available.

Lastly, if memory serves, there is a setting in the Synology that allows you to have the Synology shutdown with the server or after a given period of time. If it's not set to match the server then the Synology will ignore the FSD signal from the server.

I haven't had time to set up an experiment with my Synology to see if later versions of DSM have mucked up the nut implementation in some way.

kevindd992002

@dennypage said in NUT package:

@kevindd992002 Sorry, I'm getting ready for a long distance move and haven't had much time lately.

The lack of entries in the pfSense system log regarding the remote client would indicate that the Synology isn't actually connecting to upsd on pfSense. You can do a reboot on your Synology to confirm. You should see log out/in messages in the pfSense system log each time.

Another way to confirm... stop the ups service on pfSense. The Synology should get upset and start sending emails complaining that the ups isn't available.

Lastly, if memory serves, there is a setting in the Synology that allows you to have the Synology shutdown with the server or after a given period of time. If it's not set to match the server then the Synology will ignore the FSD signal from the server.

I haven't had time to set up an experiment with my Synology to see if later versions of DSM have mucked up the nut implementation in some way.

Ok, I just tested this. I stopped the ups service on pfsense and confirmed that the Synology had this message:

You can also see that my UPS setting there is set to "same as server" so it should follow the signal from pfsense.

BUT, I never got any email notification regarding the UPS being disconnected. I'm sure that my notification settings in Synology are working (test email, DSM update notification, etc. are all being received regularly). My notification settings are also set to these:

I then checked my Inbox and it looks like that last message I received from Synology regarding "entering battery mode" was last June 4 even though there were already several power disruptions from that time until now. So there's really something going on with how NUT and Synology is communicating. I just had another power interruption 3 days ago and when I checked the Synology logs I see "improper shutdown" events again even though I already have HOSTSYNC set to 120.

I also checked the Synology logs and it looks like that last "entered in battery mode" event that I see there was also last June 4 which was consistent with the email notification I got.

When do you think will you have time to experiment with the Synology? I can do more tests if you need me to. Just let me know what to do.

Thanks for all the help and good luck with your move!

dennypage

@kevindd992002 It will be a while before I can truly experiment. I won't actually have a UPS again for several weeks.

However, I just brought my Synology up and noticed that I didn't not receive an email indicating that the nut server was not available. Previously I always received notification from the Synology when the nut server went offline so there may indeed be an issue with newer the DSM versions.

tman222

I recently bought a new UPS to replace the smaller Cyberpower unit I was using. The model is an APC SMT1000C. And while NUT detects it fine when hooked up via USB, I'm unable to get any runtime or load information. All I see is the battery charge and a the runtime which is either 0:00:00 or 0:00:-1. The UPS itself is functioning fine -- I can see the actual projected runtime on the unit's display screen including a bunch of additional status information.

I'm curious if anyone knew of anything I can try to get this additional information to display inside the NUT package in pfSense? I suppose there is the option to buy the add-in network management card and use SNMP, but it would be great if I could things working over USB.

Thanks in advance for your help, I really appreciate it.

dennypage

@tman222 Which driver are you using?

tman222

@dennypage said in NUT package:

@tman222 Which driver are you using?

Hi @dennypage - I'm using the usbhid driver. Is this the correct one, or should I try another? I did do a bit more reading and was left with the impression that the reason I wasn't seeing all the information was the current lack of Modbus support in NUT. Could that be the case?

This is all I see under UPS Status:

Name:	ups@localhost
Summary status:	On line
Runtime (H:M:S):	0:00:-1
Battery charge:	
100%
Battery voltage:	26.3

Thanks again.

dennypage

@tman222 said in NUT package:

I did do a bit more reading and was left with the impression that the reason I wasn't seeing all the information was the current lack of Modbus support in NUT. Could that be the case?

If I had to guess, yes that would be the issue. I just ordered a SMX from APC, so I'll have a look shortly. All my other UPSs are on a moving truck somewhere...

I do have an AP9631 on order as well. If I can't get it working with USB, I'll also try SNMP.

tman222

@dennypage said in NUT package:

@tman222 said in NUT package:

I did do a bit more reading and was left with the impression that the reason I wasn't seeing all the information was the current lack of Modbus support in NUT. Could that be the case?

If I had to guess, yes that would be the issue. I just ordered a SMX from APC, so I'll have a look shortly. All my other UPSs are on a moving truck somewhere...

I do have an AP9631 on order as well. If I can't get it working with USB, I'll also try SNMP.

Thanks @dennypage - I also decided today to go ahead and order the APC AP9630 add-on network card so I can use SNMP instead as it looks like that I won't be able to get USB fully working.

bazzacad

I previously had NUT install & talking to my UPS just fine. All I had to do was select Local USB & USBHID driver & it worked perfectly. Unfortunately, I screwed up my config & locked myself out of pfSense so I restored a backup of the config, but now I can't get NUT to work again....
I've already tried the re-install package option. Any other suggestions?

dennypage

@bazzacad Did you go into UPS Settings and press Save?