UPS Service won't start after reboot

Status
Not open for further replies.
L

logan54

Explorer
Joined
May 28, 2011
Messages
56
Hello Forum,

I am using a Freenas 8.0.3-32Bit where a Cyberpower GP600 UPS is connected via USB cable.
The usb is using the usb-hid driver and the UPS Service is turned on. This setup is working well and the server will shut down as expected.

But after a reboot the service won't restart automatically, so the server doesn't recognize the UPS any more, even tough the UPS service is turn on in the service tab. I need to turn off and on this service to enable proper function again.
See the log below:

.
.
.
Jan 16 20:48:34 freenas kernel: ugen0.2: <CPS> at usbus0
Jan 16 20:48:34 freenas root: Unknown USB device: vendor 0x0764 product 0x0501 bus uhub0
Jan 16 20:48:38 freenas upsmon[1625]: UPS [ups]: connect failed: Connection failure: Connection refused
Jan 16 20:48:41 freenas kernel: ugen0.2: <CPS> at usbus0 (disconnected)
(repeated every few seconds)
.
.
(turning this service off and on again)
Jan 16 20:48:52 freenas freenas[1765]: Executing: /usr/sbin/service ix-ups quietstart
Jan 16 20:48:53 freenas kernel: ugen0.2: <CPS> at usbus0 (disconnected)
Jan 16 20:48:53 freenas upsmon[1625]: UPS [ups]: connect failed: Connection failure: Connection refused
Jan 16 20:48:53 freenas freenas[1765]: Executing: /usr/sbin/service nut restart
Jan 16 20:48:53 freenas freenas: Will not 'restart' nut because nut_enable is NO.
Jan 16 20:48:53 freenas freenas[1765]: Executing: /usr/sbin/service nut_upsmon restart
Jan 16 20:48:53 freenas freenas: Stopping nut_upsmon.
Jan 16 20:48:53 freenas upsmon[1623]: upsmon parent: read
Jan 16 20:48:53 freenas freenas: Will not 'start' nut_upsmon because nut_upsmon_enable is NO.
Jan 16 20:48:53 freenas freenas[1765]: Executing: /usr/sbin/service nut_upslog restart
Jan 16 20:48:53 freenas freenas: Stopping nut_upslog.
Jan 16 20:48:53 freenas freenas: Will not 'start' nut_upslog because nut_upslog_enable is NO.
Jan 16 20:48:54 freenas freenas[1765]: Executing: /bin/pgrep -F /var/db/nut/upsd.pid upsd
Jan 16 20:48:55 freenas freenas[1765]: Executing: /usr/sbin/service ix-ups quietstart
Jan 16 20:48:56 freenas root: Unknown USB device: vendor 0x0764 product 0x0501 bus uhub0
Jan 16 20:48:56 freenas kernel: ugen0.2: <CPS> at usbus0
Jan 16 20:48:56 freenas freenas[1765]: Executing: /usr/sbin/service nut restart
Jan 16 20:48:56 freenas freenas: nut not running? (check /var/db/nut/upsd.pid).
Jan 16 20:48:56 freenas root: Unknown USB device: vendor 0x0764 product 0x0501 bus uhub0
Jan 16 20:48:57 freenas freenas: Using subdriver: CyberPower HID 0.3
Jan 16 20:48:57 freenas freenas: Network UPS Tools - Generic HID driver 0.35 (2.6.2)
Jan 16 20:48:57 freenas freenas: USB communication driver 0.31
Jan 16 20:48:57 freenas freenas: Network UPS Tools - UPS driver controller 2.6.2
Jan 16 20:48:57 freenas freenas: Starting nut.
Jan 16 20:48:57 freenas freenas: listening on 127.0.0.1 port 3493
Jan 16 20:48:57 freenas freenas: Connected to UPS [ups]: usbhid-ups-ups
Jan 16 20:48:57 freenas freenas[1765]: Executing: /usr/sbin/service nut_upsmon restart
Jan 16 20:48:57 freenas freenas: nut_upsmon not running? (check /var/db/nut/upsmon.pid).
Jan 16 20:48:57 freenas freenas: Starting nut_upsmon.
Jan 16 20:48:57 freenas freenas: UPS: ups (master) (power value 1)
Jan 16 20:48:57 freenas freenas[1765]: Executing: /usr/sbin/service nut_upslog restart
Jan 16 20:48:57 freenas freenas: nut_upslog not running? (check /var/db/nut/upslog.pid).
Jan 16 20:48:57 freenas freenas: Starting nut_upslog.
Jan 16 20:48:57 freenas freenas[1765]: Executing: /bin/pgrep -F /var/db/nut/upsd.pid upsd

did make anyone the same observation or know a solution for this problem?

regards,

logan54
 
G

gcooper

Guest
And it's enabled in the GUI? Hmmm... Could you provide all of /var/log/messages post-boot for when nut fails to start ? Please don't include context for when you started it manually.
 
L

logan54

Explorer
Joined
May 28, 2011
Messages
56
System: FN 8.0.3-x86 (Via C7)
logan54: ---- Power outage occured

Broadcast Message from root@freenas.local
(no tty) at 19:53 CET...
Communications with UPS ups lost
Broadcast Message from root@freenas.local
(no tty) at 19:54 CET...
UPS ups on battery

Executing automatic power-fail shutdown

*** FINAL System shutdown message from root@freenas.local ***
System going down IMMEDIATELY


logan54: ---- Power returned (UPS Serivce is ON in the GUI)
Jan 19 19:59:39 freenas kernel: uhci1: [ITHREAD]
Jan 19 19:59:39 freenas kernel: usbus1: <VIA 83C572 USB controller> on uhci1
Jan 19 19:59:39 freenas kernel: uhci2: <VIA 83C572 USB controller> port 0xf000-0xf01f irq 21 at device 16.2 on pci0
Jan 19 19:59:39 freenas kernel: uhci2: [ITHREAD]
Jan 19 19:59:39 freenas kernel: usbus2: <VIA 83C572 USB controller> on uhci2
Jan 19 19:59:39 freenas kernel: ehci0: <VIA VT6202 USB 2.0 controller> mem 0xdffff000-0xdffff0ff irq 23 at device 16.4 on pci0
Jan 19 19:59:39 freenas kernel: ehci0: [ITHREAD]
Jan 19 19:59:39 freenas kernel: usbus3: EHCI version 1.0
Jan 19 19:59:39 freenas kernel: usbus3: <VIA VT6202 USB 2.0 controller> on ehci0
Jan 19 19:59:39 freenas kernel: isab0: <PCI-ISA bridge> at device 17.0 on pci0
Jan 19 19:59:39 freenas kernel: isa0: <ISA bus> on isab0
Jan 19 19:59:39 freenas kernel: pcib4: <ACPI PCI-PCI bridge> at device 19.0 on pci0
Jan 19 19:59:39 freenas kernel: pci4: <ACPI PCI bus> on pcib4
Jan 19 19:59:39 freenas kernel: pci0: <multimedia, HDA> at device 20.0 (no driver attached)
Jan 19 19:59:39 freenas kernel: atrtc0: <AT realtime clock> port 0x70-0x73 irq 8 on acpi0
Jan 19 19:59:39 freenas kernel: pmtimer0 on isa0
Jan 19 19:59:39 freenas kernel: orm0: <ISA Option ROM> at iomem 0xc0000-0xc8fff pnpid ORM0000 on isa0
Jan 19 19:59:39 freenas kernel: sc0: <System console> at flags 0x100 on isa0
Jan 19 19:59:39 freenas kernel: sc0: VGA <16 virtual consoles, flags=0x300>
Jan 19 19:59:39 freenas kernel: vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Jan 19 19:59:39 freenas kernel: atkbdc0: <Keyboard controller (i8042)> at port 0x60,0x64 on isa0
Jan 19 19:59:39 freenas kernel: atkbd0: <AT Keyboard> irq 1 on atkbdc0
Jan 19 19:59:39 freenas kernel: kbd0 at atkbd0
Jan 19 19:59:39 freenas kernel: atkbd0: [GIANT-LOCKED]
Jan 19 19:59:39 freenas kernel: atkbd0: [ITHREAD]
Jan 19 19:59:39 freenas kernel: ppc0: parallel port not found.
Jan 19 19:59:39 freenas kernel: p4tcc0: <CPU Frequency Thermal Control> on cpu0
Jan 19 19:59:39 freenas kernel: fuse4bsd: version 0.3.9-pre1, FUSE ABI 7.8
Jan 19 19:59:39 freenas kernel: Timecounter "TSC" frequency 1499844821 Hz quality 800
Jan 19 19:59:39 freenas kernel: Timecounters tick every 1.000 msec
Jan 19 19:59:39 freenas kernel: usbus0: 12Mbps Full Speed USB v1.0
Jan 19 19:59:39 freenas kernel: usbus1: 12Mbps Full Speed USB v1.0
Jan 19 19:59:39 freenas kernel: usbus2: 12Mbps Full Speed USB v1.0
Jan 19 19:59:39 freenas kernel: usbus3: 480Mbps High Speed USB v2.0
Jan 19 19:59:39 freenas kernel: ugen0.1: <VIA> at usbus0
Jan 19 19:59:39 freenas kernel: uhub0: <VIA UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0
Jan 19 19:59:39 freenas kernel: ugen1.1: <VIA> at usbus1
Jan 19 19:59:39 freenas kernel: uhub1: <VIA UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus1
Jan 19 19:59:39 freenas kernel: ugen2.1: <VIA> at usbus2
Jan 19 19:59:39 freenas kernel: uhub2: <VIA UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus2
Jan 19 19:59:39 freenas kernel: ugen3.1: <VIA> at usbus3
Jan 19 19:59:39 freenas kernel: uhub3: <VIA EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus3
Jan 19 19:59:39 freenas kernel: uhub0: 2 ports with 2 removable, self powered
Jan 19 19:59:39 freenas kernel: uhub1: 2 ports with 2 removable, self powered
Jan 19 19:59:39 freenas kernel: uhub2: 2 ports with 2 removable, self powered
Jan 19 19:59:39 freenas kernel: uhub3: 6 ports with 6 removable, self powered
Jan 19 19:59:39 freenas kernel: ugen0.2: <CPS> at usbus0
Jan 19 19:59:39 freenas kernel: ada0 at ata0 bus 0 scbus0 target 0 lun 0
Jan 19 19:59:39 freenas kernel: ada0: <WDC WD1002FBYS-02A6B0 03.00C06> ATA-8 SATA 2.x device
Jan 19 19:59:39 freenas kernel: ada0: 150.000MB/s transfers (SATA 1.x, UDMA6, PIO 8192bytes)
Jan 19 19:59:39 freenas kernel: ada0: 953869MB (1953525168 512 byte sectors: 16H 63S/T 16383C)
Jan 19 19:59:39 freenas kernel: ada1 at ata0 bus 0 scbus0 target 1 lun 0
Jan 19 19:59:39 freenas kernel: ada1: <WDC WD1002FBYS-02A6B0 03.00C06> ATA-8 SATA 2.x device
Jan 19 19:59:39 freenas kernel: ada1: 150.000MB/s transfers (SATA 1.x, UDMA6, PIO 8192bytes)
Jan 19 19:59:39 freenas kernel: ada1: 953869MB (1953525168 512 byte sectors: 16H 63S/T 16383C)
Jan 19 19:59:39 freenas kernel: ada2 at ata1 bus 0 scbus1 target 0 lun 0
Jan 19 19:59:39 freenas kernel: ada2: <TS16GCF133 20100709> ATA-7 device
Jan 19 19:59:39 freenas kernel: ada2: 66.700MB/s transfers (UDMA4, PIO 512bytes)
Jan 19 19:59:39 freenas kernel: ada2: 15296MB (31326208 512 byte sectors: 15H 63S/T 16383C)
Jan 19 19:59:39 freenas kernel: GEOM: ada2s1: geometry does not match label (16h,63s != 15h,63s).
Jan 19 19:59:39 freenas kernel: GEOM: ada2s2: geometry does not match label (16h,63s != 15h,63s).
Jan 19 19:59:39 freenas kernel: Trying to mount root from ufs:/dev/ufs/FreeNASs1a
Jan 19 19:59:39 freenas kernel: ugen0.2: <CPS> at usbus0 (disconnected)
Jan 19 19:59:39 freenas kernel: ZFS filesystem version 4
Jan 19 19:59:39 freenas kernel: ZFS storage pool version 15
Jan 19 19:59:39 freenas kernel: ugen0.2: <CPS> at usbus0
Jan 19 19:59:39 freenas kernel: ugen0.2: <CPS> at usbus0 (disconnected)
Jan 19 19:59:39 freenas kernel: ugen0.2: <CPS> at usbus0
Jan 19 19:59:39 freenas root: /etc/rc: WARNING: failed precmd routine for vmware_guestd
Jan 19 19:59:44 freenas kernel: ugen0.2: <CPS> at usbus0 (disconnected)
Jan 19 19:59:47 freenas kernel: ugen0.2: <CPS> at usbus0
Jan 19 19:59:47 freenas root: Unknown USB device: vendor 0x0764 product 0x0501 bus uhub0
Jan 19 19:59:54 freenas kernel: ugen0.2: <CPS> at usbus0 (disconnected)
Jan 19 19:59:56 freenas ntpd[1504]: ntpd 4.2.4p5-a (1)
Jan 19 19:59:56 freenas root: /etc/rc: WARNING: failed precmd routine for nut
Jan 19 19:59:56 freenas upsmon[1624]: UPS [ups]: connect failed: Connection failure: Connection refused
Jan 19 19:59:56 freenas upsmon[1624]: Communications with UPS ups lost
Jan 19 19:59:57 freenas kernel: ugen0.2: <CPS> at usbus0
Jan 19 19:59:57 freenas root: Unknown USB device: vendor 0x0764 product 0x0501 bus uhub0
Jan 19 20:00:01 freenas upsmon[1624]: UPS [ups]: connect failed: Connection failure: Connection refused
Jan 19 20:00:01 freenas upsmon[1624]: UPS ups is unavailable
Jan 19 20:00:02 freenas INADYN[1838]: I:INADYN: IP address for alias 'gruebler.no-ip.org' needs update to '188.23.100.177'
Jan 19 20:00:03 freenas INADYN[1838]: I:INADYN: Alias 'gruebler.no-ip.org' to IP '188.23.100.177' updated successful.
Jan 19 20:00:04 freenas kernel: ugen0.2: <CPS> at usbus0 (disconnected)
Jan 19 20:00:05 freenas ntpd[1505]: kernel time sync status change 2001
Jan 19 20:00:06 freenas upsmon[1624]: UPS [ups]: connect failed: Connection failure: Connection refused
Jan 19 20:00:08 freenas kernel: ugen0.2: <CPS> at usbus0
Jan 19 20:00:08 freenas root: Unknown USB device: vendor 0x0764 product 0x0501 bus uhub0
Jan 19 20:00:11 freenas upsmon[1624]: UPS [ups]: connect failed: Connection failure: Connection refused
Jan 19 20:00:14 freenas kernel: ugen0.2: <CPS> at usbus0 (disconnected)
Jan 19 20:00:16 freenas upsmon[1624]: UPS [ups]: connect failed: Connection failure: Connection refused
Jan 19 20:00:18 freenas kernel: ugen0.2: <CPS> at usbus0
Jan 19 20:00:18 freenas root: Unknown USB device: vendor 0x0764 product 0x0501 bus uhub0
Jan 19 20:00:21 freenas upsmon[1624]: UPS [ups]: connect failed: Connection failure: Connection refused
Jan 19 20:00:26 freenas upsmon[1624]: UPS [ups]: connect failed: Connection failure: Connection refused
Jan 19 20:00:26 freenas kernel: ugen0.2: <CPS> at usbus0 (disconnected)
Jan 19 20:00:29 freenas kernel: ugen0.2: <CPS> at usbus0
(repeated regularly every frew seconds.)

logan54: ---- manually shut down und restart UPS Service by GUI

Jan 19 20:06:23 freenas freenas[1764]: Executing: /usr/sbin/service nut restart
Jan 19 20:06:23 freenas freenas: nut not running? (check /var/db/nut/upsd.pid).
Jan 19 20:06:24 freenas root: Unknown USB device: vendor 0x0764 product 0x0501 bus uhub0
Jan 19 20:06:24 freenas freenas: Using subdriver: CyberPower HID 0.3
Jan 19 20:06:24 freenas freenas: Network UPS Tools - Generic HID driver 0.35 (2.6.2)
Jan 19 20:06:24 freenas freenas: USB communication driver 0.31
Jan 19 20:06:24 freenas freenas: Network UPS Tools - UPS driver controller 2.6.2
Jan 19 20:06:24 freenas freenas: Starting nut.
Jan 19 20:06:24 freenas freenas: listening on 127.0.0.1 port 3493
Jan 19 20:06:24 freenas freenas: Connected to UPS [ups]: usbhid-ups-ups
Jan 19 20:06:24 freenas freenas[1764]: Executing: /usr/sbin/service nut_upsmon restart
Jan 19 20:06:24 freenas freenas: Stopping nut_upsmon.
Jan 19 20:06:24 freenas upsmon[2940]: upsmon parent: read
Jan 19 20:06:24 freenas freenas: Starting nut_upsmon.
Jan 19 20:06:25 freenas freenas: UPS: ups (master) (power value 1)
Jan 19 20:06:25 freenas freenas[1764]: Executing: /usr/sbin/service nut_upslog restart
Jan 19 20:06:25 freenas freenas: Stopping nut_upslog.
Jan 19 20:06:25 freenas freenas: Starting nut_upslog.
Jan 19 20:06:25 freenas freenas[1764]: Executing: /bin/pgrep -F /var/db/nut/upsd.pid upsd

The UPS Service is running as expected!

regards,
logan54
 
L

logan54

Explorer
Joined
May 28, 2011
Messages
56
btw. the UPS service show allways the same behaviour, regardless if the server is shut down by the UPS or manually.

logan54
 
Status
Not open for further replies.

Similar threads

X
  • Locked
8.0.4 Release: UPS service does not start
Replies
14
Views
6K
shipkiller
S
olegsomphane
  • Locked
Freenas does not autoshutdown when UPS reports that it is running on battery mode.
Replies
8
Views
4K
sonny81
sonny81
R
  • Locked
APC BR1500G UPS - How do I get it working?
Replies
7
Views
2K
DrKK
DrKK
M
  • Locked
UPS Service authentication issue in 8.0.4 ?
Replies
6
Views
2K
mikedeissler
M
F
  • Locked
UPS Setup Help
Replies
2
Views
1K
fishinfiend
F
Top