Because SSL is not set up upsmon will not connect on Windows

[andrew-nprime]

I have been using CI snapshot builds on Windows with an APC UPS and for version 2.8.4.x it worked fine and I never thought about setting up SSL. However, 2.8.4.3467 build is the most recent one I have tried that allows upsmon to connect to upsd without SSL, despite SSL not being configured. I did try to set up SSL for it, but so far have failed. I did get the SSL setup to work with NSS on my Ubuntu server, however, so my set up shouldn't be too far off. So any help getting the SSL feature to work on Windows would be great, or allowing the upsmon to connect to upsd without using SSL would also be very helpful.

Newer upsmon that fails to connect:

C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\mingw64>sbin\upsmon.exe -DDDD
Network UPS Tools upsmon 2.8.5.106-106+g68fb8bdb7 (development iteration after 2.8.5) using a dynamic libnutprivate*
   0.001874     [D3] setproctag: starting first tagging as 'init'...
   0.004593     [D3:libupsclient] setproctag: starting first tagging as 'init'...
   0.005429     [D1:libupsclient:init] upscli_init_default_connect_timeout: upscli_default_connect_timeout=10.000000 sec assigned from: default_secs
   0.006298     [D1:init] Just failed to send signal, no daemon was running
   0.007341     [D1:init] loadconfig: Loading C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\mingw64\sbin\..\etc/upsmon.conf
   0.008859     UPS: UPS1@nprimeserver01 (primary) (power value 1)
   0.009460     Using power down flag file C:\Temp\killpower
   0.010411     [D1:init] debug level is '4'
   0.010551     [D1:init] will use a shutdown command (SHUTDOWNCMD): 'C:\WINDOWS\system32\shutdown.exe -s -t 0'
   0.011343     [D1:init] will use custom notification command (NOTIFYCMD): 'C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\mingw64\sbin\message.exe'
   0.012311     [D1:mono] common.c:2198::writepid() : this method was not fully ported for WIN32: may be not applicable to the platform
   0.014160     Init SSL without certificate database
   0.015338     Can not initialize SSL context
   0.015492     [D1:libupsclient:mono] nss_error -5977 (PR_LOAD_LIBRARY_ERROR) in upscli_init / NSS_[NoDB]_Init : Unknown error
   0.016330     [D1:mono] upsnotify: failed to notify about state NOTIFY_STATE_STOPPING: no notification tech defined, will not spam more about it
   0.016609     [D1:mono] On systems without service units, consider `export NUT_QUIET_INIT_UPSNOTIFY=true`
   0.024184     [D3:libupsclient:mono] procname_cleanup: starting for: myProcName=[C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\mingw64\sbin\upsmon.exe] myProcBaseName=[upsmon.exe] proctag=[mono] proctag_lib=[:libupsclient]
   0.025016     [D3:libupsclient:mono] proctag_cleanup:  starting for: myProcName=[C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\mingw64\sbin\upsmon.exe] myProcBaseName=[upsmon.exe] proctag=[mono] proctag_lib=[:libupsclient]
   0.025796     [D2:libupsclient:mono] library (:libupsclient) used by a upsmon sub-process (mono) is exiting now
   0.026395     [D3:mono] procname_cleanup: starting for: myProcName=[C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\mingw64\sbin\upsmon.exe] myProcBaseName=[upsmon.exe] proctag=[mono] proctag_lib=[(null)]
   0.027131     [D3:mono] proctag_cleanup:  starting for: myProcName=[C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\mingw64\sbin\upsmon.exe] myProcBaseName=[upsmon.exe] proctag=[mono] proctag_lib=[(null)]
   0.028264     [D2:mono] a upsmon sub-process (mono) is exiting now

Older upsmon that works without SSL:

C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.4.3467-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.4.3467-master\mingw64>sbin\upsmon -DDDD
Network UPS Tools upsmon 2.8.4.8-8+g0459ffb8d (development iteration after 2.8.4)
   0.000000     [D1] Just failed to send signal, no daemon was running
   0.083829     [D1] loadconfig: Loading C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.4.3467-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.4.3467-master\mingw64\sbin\..\etc/upsmon.conf
   0.133280     UPS: UPS1@nprimeserver01 (primary) (power value 1)
   0.141850     Using power down flag file C:\Temp\killpower
   0.147932     [D1] debug level is '4'
   0.150440     [D1] will use a shutdown command (SHUTDOWNCMD): 'C:\WINDOWS\system32\shutdown.exe -s -t 0'
   0.156898     [D1] will use custom notification command (NOTIFYCMD): 'C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.4.3467-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.4.3467-master\mingw64\sbin\message.exe'
   0.169515     [D1] common.c:1628::writepid() : this method was not fully ported for WIN32: may be not applicable to the platform
   0.190434     upsnotify: failed to notify about state NOTIFY_STATE_READY_WITH_PID: no notification tech defined, will not spam more about it
   0.197566     [D1] On systems without service units, consider `export NUT_QUIET_INIT_UPSNOTIFY=true`
   0.207031     [D1] Trying to connect to UPS [UPS1@nprimeserver01]
   0.221051     [D1] Logged into UPS UPS1@nprimeserver01
   0.227910     [D2] pollups: UPS1@nprimeserver01
   0.230032     [D1] upsmon.c:1083::set_alarm() : this method was not fully ported for WIN32: may be not applicable to the platform
   0.236349     [D3] get_var: UPS1@nprimeserver01 / status
   0.239985     [D3] get_var: UPS1@nprimeserver01 / buzzword
   0.246692     [D3] get_var: UPS1@nprimeserver01 / X-buzzword
   0.249919     [D1] upsmon.c:1100::clear_alarm() : this method was not fully ported for WIN32: may be not applicable to the platform
   0.256060     [D1] upsmon.c:1100::clear_alarm() : this method was not fully ported for WIN32: may be not applicable to the platform
   0.266050     [D2] parse_status: [OL]
   0.268672     [D3] parsing: [OL]
   0.270726     [D3] ups_on_line: UPS1@nprimeserver01 (first time)
   0.274158     [D3] Handled 1 status tokens
   0.276690     [D3] Current power value: 1
   0.279114     [D3] Minimum power value: 1
   0.284392     [D4] Beginning 5-sec delay between main loop cycles
   5.282609     [D4] 5-sec delay between main loop cycles finished, took 4.998185
   5.290092     [D2] pollups: UPS1@nprimeserver01

[jimklimov]

Interesting, thanks! I guess this is some fallout of recent work on getting SSL to work at all (there were numerous mishaps about it).

Daemons are supposed to exit if they are required to have SSL but could not make it; however if it is only a nice-to-have (not required by config files), they shouldn't abort.

[jimklimov]

Are you 100% sure there are no mentions of CERT* etc. configuration values in your config? Maybe something leaked from tests to (sample) config files (shouldn't have, test mocks live in a separate directory).

This line worries me:

Init SSL with certificate database located at C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\mingw64\nut_cert_db

And there is no mention of nut_cert_db in the code base...

On the other hand, in the commit you used (current master branch tip) the changes since v2.8.4 tag in upscli_init() and upsmon around its usage were minimal, e.g. it did return -1 upon NoDB before, and did fatalx() exit as a result.

I suppose earlier your deployment did not have the bits of SSL config, of whatever provenance, and without them, the upscli_init() method just returned 0 earlier, and the client went on. With the configs it can not fulfill, especially as critical as requested security, failing instead of misleading is a design choice. So where did that nut_cert_db come from, that is the question :)

[andrew-nprime]

Are you 100% sure there are no mentions of CERT* etc. configuration values in your config? Maybe something leaked from tests to (sample) config files (shouldn't have, test mocks live in a separate directory).

This line worries me:

Init SSL with certificate database located at C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\mingw64\nut_cert_db

And there is no mention of nut_cert_db in the code base...

On the other hand, in the commit you used (current master branch tip) the changes since v2.8.4 tag in upscli_init() and upsmon around its usage were minimal, e.g. it did return -1 upon NoDB before, and did fatalx() exit as a result.

I suppose earlier your deployment did not have the bits of SSL config, of whatever provenance, and without them, the upscli_init() method just returned 0 earlier, and the client went on. With the configs it can not fulfill, especially as critical as requested security, failing instead of misleading is a design choice. So where did that nut_cert_db come from, that is the question :)

You are quite right, I initially posted the output from the newer upsmon with my attempt at setting up a secure connection in the config using nut_cert_db as the folder to store the NSS database. I have now updated the initial post with the output from the newer upsmon when there are no configured SSL settings in upsmon.conf

[andrew-nprime]

This may also be related, when I try to talk to another NUT server on the network, now that it is set up to use SSL if possible, the newer upsc gives this output:

C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\mingw64>bin\upsc -DDDD UPS2@stockman
   0.000458     [D3] setproctag: starting first tagging as 'upsc'...
   0.007644     [D1:upsc] Starting NUT client: upsc
   0.010774     [D1:upsc] upscli_init_default_connect_timeout: upscli_default_connect_timeout=10.000000 sec assigned from: default_secs
   0.011989     [D1:UPS2@stockman] upsname='UPS2' hostname='stockman' port='3493'
   0.032695     [D3:UPS2@stockman] upscli not initialized, force initialisation without SSL configuration
   0.033538     Init SSL without certificate database
   0.035455     Can not initialize SSL context
   0.035700     [D1:UPS2@stockman] nss_error -5977 (PR_LOAD_LIBRARY_ERROR) in upscli_init / NSS_[NoDB]_Init : Unknown error
   0.036910     [D3:UPS2@stockman] upscli_sslinit: Trying to STARTTLS
   0.039458     [D1:UPS2@stockman] nss_error -8038 (SEC_ERROR_NOT_INITIALIZED) in upscli_sslinit / SSL_ImportFD : NSS is not initialized.
   0.041780     Error while connecting to NUT server stockman, disconnect
   0.045898     [D1:UPS2@stockman] upscli_disconnect: We logged out, and server said '���', not OK but oh well
   0.057250     Error: Unknown error
   0.058070     [D1:UPS2@stockman] clean_exit: finished, exiting
   0.058866     [D3:UPS2@stockman] procname_cleanup: starting for: myProcName=[C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\mingw64\bin\upsc.exe] myProcBaseName=[upsc.exe] proctag=[UPS2@stockman] proctag_lib=[(null)]
   0.059901     [D3:UPS2@stockman] proctag_cleanup:  starting for: myProcName=[C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\mingw64\bin\upsc.exe] myProcBaseName=[upsc.exe] proctag=[UPS2@stockman] proctag_lib=[(null)]
   0.151059     [D2:UPS2@stockman] a upsc sub-process (UPS2@stockman) is exiting now

And the older one doesn't recognise the -D option, and gives this:

C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.4.3467-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.4.3467-master\mingw64>bin\upsc  UPS2@stockman
ssl_error() ret=-1 SSL_ERROR_WANT_READ
Error while connecting to NUT server stockman, disconnect
Error: Unknown error

whereas on Ubuntu with SSL set up it gives:

andrew@stockman:~$ upsc UPS2@stockman
Init SSL without certificate database
Connecting in SSL to 'stockman' (no certificate name specified)
Do not intend to authenticate server stockman
SSL handshake done successfully with server stockman
Connected to NUT server stockman in SSL
Certificate verification is disabled
battery.charge: 100
battery.charge.low: 30

and on debian without SSL set up it gives:

andrewrule@3cx:~$ upsc UPS2@stockman
Init SSL without certificate database
Connecting in SSL to 'stockman' (no certificate name specified)
Do not intend to authenticate server stockman
SSL handshake done successfully with server stockman
Connected to NUT server stockman in SSL
Certificate verification is disabled
battery.charge: 100
battery.charge.low: 30

[jimklimov]

Can you please check if the servers have any CERTREQUEST setting -- e.g. want the client to present some certificate (1), or specifically one that passes trust checks (2)? This is a special build option so far, that not all clients have a way to configure certs at all (#3329)... I wonder if that somehow got enabled in CI builds and leaked to the tarballs?

[andrew-nprime]

Can you please check if the servers have any CERTREQUEST setting -- e.g. want the client to present some certificate (1), or specifically one that passes trust checks (2)? This is a special build option so far, that not all clients have a way to configure certs at all (#3329)... I wonder if that somehow got enabled in CI builds and leaked to the tarballs?

In upsd.conf the CERTREQUEST setting is currently commented out on the Windows server. Does that answer your question?

I also tried setting CERTREQUEST 0 in the upsd.conf, but it made no difference to upsmon or upsc. BTW, upsc will connect to the windows upsd server, and did also connect to the ubuntu linux upsd server before that one had SSL set up on it.

The output when upsc talks to the Windows server upsd starts like this:

C:\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\NUT-for-Windows-x86_64-SNAPSHOT-2.8.5.4570-master\mingw64>bin\upsc UPS1@nprimeserver01
Init SSL without certificate database
Can not initialize SSL context
battery.charge: 100
battery.charge.low: 10

[jimklimov]

Yes, I hope so :D