Additional debug information not working

In the configuration section for logging https://www.shinyproxy.io/configuration/#logging there is an option for specifying additional log information

logging:
level:
org.springframework.security.ldap.authentication: DEBUG
org.springframework.security.ldap.userdetails: DEBUG
file:
shinyproxy.log

I have put this in my application.yml file but I don’t see any additional information in shinyproxy.log, does it appear in another file?

Hi @akenny,

Not sure if that’s just copy-paste behaviour, but your post isn’t properly indented. Can you confirm that your yml file is?

The additional logging should indeed appear in the same log file that is in your working directory.

Hi @fmichielssen

Sorry yes that is a pasting issue.
The following image shows how it is indented. Is this correct?

image

Yes, that looks correct.
I’m not sure what could be going wrong here. I just tried and got debug logging:

2018-02-27 10:08:43.029 DEBUG 12636 — [ XNIO-2 task-8] o.s.s.l.a.LdapAuthenticationProvider : Processing authentication request for user: tesla
2018-02-27 10:08:43.042 DEBUG 12636 — [ XNIO-2 task-8] o.s.s.l.a.BindAuthenticator : Attempting to bind as uid=tesla,dc=example,dc=com
2018-02-27 10:08:43.243 DEBUG 12636 — [ XNIO-2 task-8] o.s.s.l.a.BindAuthenticator : Retrieving attributes…
2018-02-27 10:08:43.334 DEBUG 12636 — [ XNIO-2 task-8] .s.s.l.u.DefaultLdapAuthoritiesPopulator : Getting authorities for user uid=tesla,dc=example,dc=com
2018-02-27 10:08:43.334 DEBUG 12636 — [ XNIO-2 task-8] .s.s.l.u.DefaultLdapAuthoritiesPopulator : Searching for roles for user ‘tesla’, DN = ‘uid=tesla,dc=example,dc=com’, with filter (uniqueMember={0}) in search base ''
2018-02-27 10:08:43.602 DEBUG 12636 — [ XNIO-2 task-8] .s.s.l.u.DefaultLdapAuthoritiesPopulator : Roles from search: [Scientists]
2018-02-27 10:08:43.603 DEBUG 12636 — [ XNIO-2 task-8] o.s.s.l.u.LdapUserDetailsMapper : Mapping user details from context with DN: uid=tesla,dc=example,dc=com

Are you also certain that this is the yml being read by shinyproxy? I.e. it is located in the working directory of the process?

It is in the same folder as the .jar file yes

This is the current output with the above application.yml file when I attempt a login.

2018-03-21 15:39:28.304  INFO 17160 --- [           main] eu.openanalytics.ShinyProxyApplication   : Started ShinyProxyApplication in 5.972 seconds (JVM running for 6.488)
2018-03-21 15:39:34.113  INFO 17160 --- [  XNIO-2 task-2] io.undertow.servlet                      : Initializing Spring FrameworkServlet 'dispatcherServlet'
2018-03-21 15:39:34.113  INFO 17160 --- [  XNIO-2 task-2] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization started
2018-03-21 15:39:34.128  INFO 17160 --- [  XNIO-2 task-2] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization completed in 15 ms
2018-03-21 15:39:49.180 DEBUG 17160 --- [  XNIO-2 task-3] o.s.s.l.a.LdapAuthenticationProvider     : Processing authentication request for user: currentUser
2018-03-21 15:39:49.181  INFO 17160 --- [  XNIO-2 task-3] eu.openanalytics.services.UserService    : Authentication failure [user: currentUser] [error: Bad credentials]

When I run with the --debug flag(java -jar shinyproxy-1.0.2.jar --debug) I do get the following messages on startup:

2018-03-21 15:45:29.218  INFO 19138 --- [           main] eu.openanalytics.ShinyProxyApplication   : Starting ShinyProxyApplication v1.0.2 on aws13shi02 with PID 19138 (/home/shinyproxy/target/shinyproxy-1.0.2.jar started by root in /home/shinyproxy/target)
2018-03-21 15:45:29.228  INFO 19138 --- [           main] eu.openanalytics.ShinyProxyApplication   : No active profile set, falling back to default profiles: default
2018-03-21 15:45:29.228 DEBUG 19138 --- [           main] o.s.boot.SpringApplication               : Loading source class eu.openanalytics.ShinyProxyApplication
2018-03-21 15:45:29.654 DEBUG 19138 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Loaded config file 'file:./application.yml' (file:./application.yml)
2018-03-21 15:45:29.654 DEBUG 19138 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Skipped (empty) config file 'file:./application.yml' (file:./application.yml) for profile default

Is this a clue?

Hi @akenny

If you’re not sure where if your working folder then just find your shinyproxy.service file…
try

$ locate shinyproxy.service

it should be in /etc/systemd/system/ folder…
My working dir is /etc/shinyproxy

If you do not run shinyproxy as a service then how are you running it?

My shinyproxy.service file is located here:
/home/shinyproxy/src/deb/shinyproxy.service

And contains the following:
[Unit]
Description=ShinyProxy
After=syslog.target network.target

[Service]
Type=simple
User=shinyproxy
Group=shinyproxy
WorkingDirectory=/etc/shinyproxy
ExecStart=/usr/bin/java -jar /opt/shinyproxy/shinyproxy.jar
ExecReload=/bin/kill -HUP $MAINPID
KillMode=process
PIDFile=/run/shinyproxy.lock

[Install]
WantedBy=multi-user.target

I have not read about this file anywhere, what does it do?

My shinyproxy folder is located in:
/home

And I run it by running the jar file in the target folder where my application.yml is also located.

If I make changes in that .yml file such as adding/removing applications then it affects what I see in the browser so I would think it is being read just fine

Your working directory for service is in

There you should have your application.yml file…

Try start / restart / stop like that:

service shinyproxy start
service shinyproxy stop
service shinyproxy restart