search

linuxmuster / linuxmuster-webui7

Next generation web interface for linuxmuster.net v7.
https://www.linuxmuster.net
GNU General Public License v3.0
12 stars 8 forks source link

schooladmin cannot switch into "List Management" view - Server error occured. This is likely a bug. #189

Closed delacroix0815 closed 3 years ago

delacroix0815 commented 3 years ago

As global-admin, i created several school-admins, but none of them can switch into the Listmanagement view - Screenshot below.

Bildschirmfoto_2021-08-31_23-32-44

As global-admin, it works. I think this bug has been mentioned in the forums already: https://ask.linuxmuster.net/t/webui-this-is-likely-a-bug-schul-administrator-erstellt/6304. Unfortunately i dont get any traceback output as seen in the screenshot. Has this been fixed already in git?

kiarn commented 3 years ago

Hello,

The error mentioned in the forum should be fixed and published since last year. I cannot reproduce this problem. Do you have more informations in /var/log/ajenti/ajenti.log ?

delacroix0815 commented 3 years ago

Not much unfortunately:

root@server:~# tail -f /var/log/ajenti/ajenti.log 2021-08-31 23:43:27,213 INFO : SSL enabled 2021-08-31 23:43:27,359 INFO : New worker "restricted session" PID 1056, EUID 0, EGID 0 2021-08-31 23:43:27,360 INFO : Worker 1056 is demoting to UID 65534 / GID 65534... 2021-08-31 23:43:27,360 INFO : ...done, new EUID 65534 EGID 65534 2021-08-31 23:44:27,258 INFO : Opening a session for user global-admin 2021-08-31 23:44:27,259 INFO : Opening a new worker gate for session 1, client 10.0.255.1 2021-08-31 23:44:27,275 INFO : New worker "session 1" PID 1076, EUID 0, EGID 0 2021-08-31 23:44:27,281 INFO : Authenticating session as global-admin 2021-08-31 23:44:32,480 INFO : Detected encoding for /etc/linuxmuster/sophomorix/default-school/students.csv : utf-8 2021-08-31 23:44:32,493 INFO : Detected encoding for /etc/linuxmuster/sophomorix/default-school/students.csv : utf-8 2021-08-31 23:53:16,672 INFO : Opening a session for user createc 2021-08-31 23:53:16,673 INFO : Opening a new worker gate for session 2, client 10.0.255.1 2021-08-31 23:53:16,694 INFO : New worker "session 2" PID 1419, EUID 0, EGID 0 2021-08-31 23:53:16,697 INFO : Authenticating session as createc 2021-08-31 23:53:48,492 INFO : Opening a session for user global-admin 2021-08-31 23:53:48,492 INFO : Opening a new worker gate for session 3, client 10.0.255.1 2021-08-31 23:53:48,504 INFO : New worker "session 3" PID 1452, EUID 0, EGID 0 2021-08-31 23:53:48,509 INFO : Authenticating session as global-admin 2021-08-31 23:53:55,586 INFO : Detected encoding for /etc/linuxmuster/sophomorix/default-school/students.csv : utf-8 2021-08-31 23:53:55,620 INFO : Detected encoding for /etc/linuxmuster/sophomorix/default-school/students.csv : utf-8 2021-08-31 23:54:09,147 INFO : Opening a session for user createc 2021-08-31 23:54:09,147 INFO : Opening a new worker gate for session 4, client 10.0.255.1 2021-08-31 23:54:09,160 INFO : New worker "session 4" PID 1485, EUID 0, EGID 0 2021-08-31 23:54:09,161 INFO : Authenticating session as createc

I logged in as schooladmin 'createc' first tried to switch to the ListView Panel, then as 'global-admin', then as 'createc' again, as seen in the output above.

'fixed and published last year' -- meaning it should already be on our system when we ran apt update && apt dist-upgrade?

kiarn commented 3 years ago

Ok, the logs don't show anything interesting.

If you want, you can try to activate the debug mode : 

vim /lib/systemd/system/linuxmuster-webui.service

Change :

ExecStart=/usr/bin/python3 /usr/local/bin/ajenti-panel -d --stock-plugins --plugins /usr/lib/linuxmuster-webui/plugins

to

ExecStart=/usr/bin/python3 /usr/local/bin/ajenti-panel -d --stock-plugins --plugins /usr/lib/linuxmuster-webui/plugins --log debug

and then : 

systemctl daemon-reload
systemctl restart linuxmuster-webui.service

This way we may have more informations about the problem.

'fixed and published last year' -- meaning it should already be on our system when we ran apt update && apt dist-upgrade?

If it's the same problem, yes, it should already be fixed on your system :)

Arnaud

delacroix0815 commented 3 years ago

Debug output during login as 'createc':

root@server:~# tail -f /var/log/ajenti/ajenti.log 2021-09-01 00:40:13,474 DEBUG : Validating WebSocket request 2021-09-01 00:40:13,474 DEBUG : Attempting to upgrade connection 2021-09-01 00:40:13,474 DEBUG : WebSocket request accepted, switching protocols 2021-09-01 00:40:13,475 DEBUG : Spawning sub-Socket Greenlet: send_into_ws 2021-09-01 00:40:13,475 DEBUG : Spawning sub-Socket Greenlet: read_from_ws 2021-09-01 00:40:13,475 DEBUG : Spawning sub-Socket Greenlet: _heartbeat 2021-09-01 00:40:13,475 DEBUG : Spawning sub-Socket Greenlet: _heartbeat_timeout 2021-09-01 00:40:13,705 DEBUG : Socket 139842761124888 connected 2021-09-01 00:40:13,938 DEBUG : ... GET /api/core/tasks/request-update 2021-09-01 00:40:13,938 DEBUG : 0.002s 0.0 bytes 401 GET /api/core/tasks/request-update 2021-09-01 00:40:22,028 DEBUG : ... POST /api/core/auth 2021-09-01 00:40:22,147 INFO : Opening a session for user createc 2021-09-01 00:40:22,148 INFO : Opening a new worker gate for session 1, client 10.0.255.1 2021-09-01 00:40:22,149 DEBUG : Invoke target <bound method WorkerGate._target of <aj.gate.gate.WorkerGate object at 0x7f2fae19ecf8>> in child process. 2021-09-01 00:40:22,153 DEBUG : SIGCHLD watcher for 2173 started. 2021-09-01 00:40:22,155 DEBUG : Invalidate <_GIPCWriter_024069 fd: 27> in parent. 2021-09-01 00:40:22,155 DEBUG : Invalidating <_GIPCWriter_024069 fd: 27> ... 2021-09-01 00:40:22,156 DEBUG : Invalidate <_GIPCReader_dd55c3 fd: 28> in parent. 2021-09-01 00:40:22,157 DEBUG : Invalidating <_GIPCReader_dd55c3 fd: 28> ... 2021-09-01 00:40:22,157 DEBUG : Started child process 2173 2021-09-01 00:40:22,158 DEBUG : _child start. target: <bound method WorkerGate._target of <aj.gate.gate.WorkerGate object at 0x7f2fae19ecf8>> 2021-09-01 00:40:22,159 DEBUG : New session 1 2021-09-01 00:40:22,159 DEBUG : Delete current hub's threadpool. 2021-09-01 00:40:22,159 DEBUG : Destroy hub and default loop. 2021-09-01 00:40:22,160 DEBUG : 0.136s 40.0 bytes 200 POST /api/core/auth 2021-09-01 00:40:22,160 DEBUG : Created new hub and default event loop. 2021-09-01 00:40:22,160 DEBUG : Invalidate <_GIPCReader_9e51b3 fd: 9> in child. 2021-09-01 00:40:22,160 DEBUG : Legitimate <_GIPCReader_9e51b3 fd: 9> for current process. 2021-09-01 00:40:22,161 DEBUG : Invalidating <_GIPCReader_9e51b3 fd: 9> ... 2021-09-01 00:40:22,161 DEBUG : Invalidate <_GIPCWriter_84ca5a fd: 15> in child. 2021-09-01 00:40:22,161 DEBUG : Legitimate <_GIPCWriter_84ca5a fd: 15> for current process. 2021-09-01 00:40:22,161 DEBUG : Invalidating <_GIPCWriter_84ca5a fd: 15> ... 2021-09-01 00:40:22,161 DEBUG : Invalidate <_GIPCReader_d2438b fd: 26> in child. 2021-09-01 00:40:22,161 DEBUG : Legitimate <_GIPCReader_d2438b fd: 26> for current process. 2021-09-01 00:40:22,161 DEBUG : Invalidating <_GIPCReader_d2438b fd: 26> ... 2021-09-01 00:40:22,162 DEBUG : Invalidate <_GIPCWriter_662bf0 fd: 29> in child. 2021-09-01 00:40:22,162 DEBUG : Legitimate <_GIPCWriter_662bf0 fd: 29> for current process. 2021-09-01 00:40:22,171 DEBUG : Invalidating <_GIPCWriter_662bf0 fd: 29> ... 2021-09-01 00:40:22,171 DEBUG : Legitimate <_GIPCWriter_024069 fd: 27> for current process. 2021-09-01 00:40:22,171 DEBUG : Handle <_GIPCWriter_024069 fd: 27> is now valid in child. 2021-09-01 00:40:22,171 DEBUG : Legitimate <_GIPCReader_dd55c3 fd: 28> for current process. 2021-09-01 00:40:22,171 DEBUG : Handle <_GIPCReader_dd55c3 fd: 28> is now valid in child. 2021-09-01 00:40:22,173 INFO : New worker "session 1" PID 2173, EUID 0, EGID 0 2021-09-01 00:40:22,174 INFO : Authenticating session as createc 2021-09-01 00:40:22,273 DEBUG : Authentication provider "Linux Muster LDAP" maps "createc" -> 0 2021-09-01 00:40:22,467 DEBUG : Closed WebSocket 2021-09-01 00:40:22,534 DEBUG : ... GET / 2021-09-01 00:40:22,541 DEBUG : 0.010s 0.0 bytes 302 GET / 2021-09-01 00:40:22,796 DEBUG : ... GET /view/ 2021-09-01 00:40:22,800 DEBUG : 0.005s 11.0 KB 200 GET /view/ 2021-09-01 00:40:23,126 DEBUG : ... GET /resources/all.vendor.css 2021-09-01 00:40:23,139 DEBUG : ... GET /resources/all.vendor.js 2021-09-01 00:40:23,139 DEBUG : 0.036s 6.3 KB 200 GET /resources/all.vendor.css 2021-09-01 00:40:23,376 DEBUG : ... GET /resources/all.css 2021-09-01 00:40:23,377 DEBUG : 0.266s 645.3 KB 200 GET /resources/all.vendor.js 2021-09-01 00:40:23,381 DEBUG : ... GET /resources/all.partials.js 2021-09-01 00:40:23,382 DEBUG : 0.268s 28.0 KB 200 GET /resources/all.css 2021-09-01 00:40:23,405 DEBUG : ... GET /resources/all.js 2021-09-01 00:40:23,405 DEBUG : 0.289s 47.6 KB 200 GET /resources/all.partials.js 2021-09-01 00:40:23,431 DEBUG : ... GET /resources/all.init.js 2021-09-01 00:40:23,437 DEBUG : 0.317s 56.5 KB 200 GET /resources/all.js 2021-09-01 00:40:23,439 DEBUG : 0.314s 309.0 bytes 200 GET /resources/all.init.js 2021-09-01 00:40:24,273 DEBUG : ... GET /resources/all.locale.js 2021-09-01 00:40:24,275 DEBUG : 0.012s 13.3 KB 200 GET /resources/all.locale.js 2021-09-01 00:40:24,281 DEBUG : ... GET /api/core/identity 2021-09-01 00:40:24,325 DEBUG : 0.047s 1.1 KB 200 GET /api/core/identity 2021-09-01 00:40:24,328 DEBUG : ... GET /api/core/session-time 2021-09-01 00:40:24,331 DEBUG : Sending a session list update to restricted session 2021-09-01 00:40:24,333 DEBUG : Sending a session list update to session 1 2021-09-01 00:40:24,334 DEBUG : ... GET /api/core/sidebar 2021-09-01 00:40:24,335 DEBUG : ... GET /api/core/sidebar 2021-09-01 00:40:24,340 DEBUG : ... GET /resources/all.locale.js 2021-09-01 00:40:24,341 DEBUG : Received a session list update 2021-09-01 00:40:24,341 DEBUG : 0.046s 4.0 bytes 200 GET /api/core/session-time 2021-09-01 00:40:24,341 DEBUG : 0.044s 2.2 KB 200 GET /api/core/sidebar 2021-09-01 00:40:24,342 DEBUG : 0.043s 2.2 KB 200 GET /api/core/sidebar 2021-09-01 00:40:24,342 DEBUG : 0.042s 13.3 KB 200 GET /resources/all.locale.js 2021-09-01 00:40:24,344 DEBUG : Received a session list update 2021-09-01 00:40:24,515 DEBUG : ... GET /api/core/session-time 2021-09-01 00:40:24,515 DEBUG : Sending a session list update to restricted session 2021-09-01 00:40:24,516 DEBUG : Sending a session list update to session 1 2021-09-01 00:40:24,517 DEBUG : Received a session list update 2021-09-01 00:40:24,517 DEBUG : Received a session list update 2021-09-01 00:40:24,526 DEBUG : 0.013s 4.0 bytes 200 GET /api/core/session-time 2021-09-01 00:40:24,569 DEBUG : ... GET /api/core/session-time 2021-09-01 00:40:24,570 DEBUG : Sending a session list update to restricted session 2021-09-01 00:40:24,571 DEBUG : Sending a session list update to session 1 2021-09-01 00:40:24,571 DEBUG : Received a session list update 2021-09-01 00:40:24,572 DEBUG : Received a session list update 2021-09-01 00:40:24,580 DEBUG : 0.012s 4.0 bytes 200 GET /api/core/session-time 2021-09-01 00:40:24,589 DEBUG : ... GET /api/lm/setup-wizard/is-configured 2021-09-01 00:40:24,590 DEBUG : 0.003s 4.0 bytes 200 GET /api/lm/setup-wizard/is-configured 2021-09-01 00:40:24,641 DEBUG : ... GET /api/lmn/quota/createc 2021-09-01 00:40:24,645 DEBUG : Popen: ['sophomorix-query', '--sam', 'createc', '--user-full', '--quota-usage', '-jj'] 2021-09-01 00:40:25,405 DEBUG : Initializing WebSocket 2021-09-01 00:40:25,406 DEBUG : Validating WebSocket request 2021-09-01 00:40:25,406 DEBUG : Attempting to upgrade connection 2021-09-01 00:40:25,407 DEBUG : WebSocket request accepted, switching protocols 2021-09-01 00:40:25,408 DEBUG : Spawning sub-Socket Greenlet: send_into_ws 2021-09-01 00:40:25,408 DEBUG : Spawning sub-Socket Greenlet: read_from_ws 2021-09-01 00:40:25,408 DEBUG : Spawning sub-Socket Greenlet: _heartbeat 2021-09-01 00:40:25,408 DEBUG : Spawning sub-Socket Greenlet: _heartbeat_timeout 2021-09-01 00:40:25,631 DEBUG : Socket 139842761078096 connected 2021-09-01 00:40:25,633 DEBUG : Socket namespace 139842761078096 created 2021-09-01 00:40:25,634 DEBUG : Spawning sub-Socket Greenlet (in a namespace): _reader 2021-09-01 00:40:25,745 DEBUG : 1.106s 4.6 KB 200 GET /api/lmn/quota/createc 2021-09-01 00:40:25,858 DEBUG : ... GET /api/core/tasks/request-update 2021-09-01 00:40:25,859 DEBUG : 0.003s 4.0 bytes 200 GET /api/core/tasks/request-update 2021-09-01 00:40:30,802 DEBUG : ... GET /api/core/session-time 2021-09-01 00:40:30,803 DEBUG : Sending a session list update to restricted session 2021-09-01 00:40:30,804 DEBUG : Sending a session list update to session 1 2021-09-01 00:40:30,804 DEBUG : Received a session list update 2021-09-01 00:40:30,805 DEBUG : Received a session list update 2021-09-01 00:40:30,816 DEBUG : 0.015s 4.0 bytes 200 GET /api/core/session-time 2021-09-01 00:40:30,835 DEBUG : ... GET /api/lm/schoolsettings 2021-09-01 00:40:30,838 DEBUG : 0.005s 6.0 KB 500 GET /api/lm/schoolsettings 2021-09-01 00:41:10,721 DEBUG : heartbeat timed out, killing socket 2021-09-01 00:41:10,722 DEBUG : Calling disconnect() on sessid='13154675208334154' client_queue[2] server_queue[1] hits=1 2021-09-01 00:41:10,722 DEBUG : Socket 139842760967000 disconnected 2021-09-01 00:41:10,723 DEBUG : Removing sessid='13154675208334154' client_queue[2] server_queue[1] hits=1 from server sockets 2021-09-01 00:41:13,706 DEBUG : heartbeat timed out, killing socket 2021-09-01 00:41:13,707 DEBUG : Calling disconnect() on sessid='15443866619911994' client_queue[2] server_queue[1] hits=1 2021-09-01 00:41:13,707 DEBUG : Socket 139842761124888 disconnected 2021-09-01 00:41:13,707 DEBUG : Removing sessid='15443866619911994' client_queue[2] server_queue[1] hits=1 from server sockets

delacroix0815 commented 3 years ago

As global-admin:

2021-09-01 00:42:36,449 DEBUG : ... GET /api/core/logout

2021-09-01 00:42:36,450 DEBUG : 0.003s 4.0 bytes 200 GET /api/core/logout 2021-09-01 00:42:37,211 DEBUG : Closed WebSocket 2021-09-01 00:42:37,228 DEBUG : Destroying session 1 2021-09-01 00:42:37,229 DEBUG : Stopping child process 2173 2021-09-01 00:42:37,234 DEBUG : SIGCHLD watcher callback for 2173 invoked. Exitcode stored: -15 2021-09-01 00:42:37,234 DEBUG : Invalidating <_GIPCWriter_662bf0 fd: 29> ... 2021-09-01 00:42:37,234 DEBUG : Invalidating <_GIPCReader_d2438b fd: 26> ... 2021-09-01 00:42:37,237 DEBUG : ... GET /view/login/normal//view/lm/users/listmanagement 2021-09-01 00:42:37,238 DEBUG : 0.010s 11.0 KB 200 GET /view/login/normal//view/lm/users/listmanagement 2021-09-01 00:42:37,526 DEBUG : ... GET /resources/all.vendor.css 2021-09-01 00:42:37,527 DEBUG : 0.004s 6.3 KB 200 GET /resources/all.vendor.css 2021-09-01 00:42:37,788 DEBUG : ... GET /resources/all.css 2021-09-01 00:42:37,793 DEBUG : 0.016s 28.0 KB 200 GET /resources/all.css 2021-09-01 00:42:37,796 DEBUG : ... GET /resources/all.init.js 2021-09-01 00:42:37,796 DEBUG : ... GET /resources/all.vendor.js 2021-09-01 00:42:37,796 DEBUG : 0.008s 309.0 bytes 200 GET /resources/all.init.js 2021-09-01 00:42:37,974 DEBUG : ... GET /resources/all.js 2021-09-01 00:42:37,980 DEBUG : 0.188s 645.3 KB 200 GET /resources/all.vendor.js 2021-09-01 00:42:37,987 DEBUG : ... GET /resources/all.partials.js 2021-09-01 00:42:37,987 DEBUG : 0.193s 56.5 KB 200 GET /resources/all.js 2021-09-01 00:42:38,003 DEBUG : 0.198s 47.6 KB 200 GET /resources/all.partials.js 2021-09-01 00:42:38,731 DEBUG : ... GET /resources/all.locale.js 2021-09-01 00:42:38,735 DEBUG : ... GET /api/core/identity 2021-09-01 00:42:38,736 DEBUG : 0.006s 13.3 KB 200 GET /resources/all.locale.js 2021-09-01 00:42:38,737 DEBUG : 0.004s 193.0 bytes 200 GET /api/core/identity 2021-09-01 00:42:38,741 DEBUG : ... GET /api/core/session-time 2021-09-01 00:42:38,741 DEBUG : ... GET /api/core/sidebar 2021-09-01 00:42:38,742 DEBUG : ... GET /api/core/sidebar 2021-09-01 00:42:38,742 DEBUG : 0.008s 0.0 bytes 401 GET /api/core/session-time 2021-09-01 00:42:38,743 DEBUG : 0.003s 0.0 bytes 401 GET /api/core/sidebar 2021-09-01 00:42:38,743 DEBUG : 0.002s 0.0 bytes 401 GET /api/core/sidebar 2021-09-01 00:42:38,746 DEBUG : ... GET /resources/all.locale.js 2021-09-01 00:42:38,749 DEBUG : 0.005s 13.3 KB 200 GET /resources/all.locale.js 2021-09-01 00:42:38,953 DEBUG : ... GET /api/core/session-time 2021-09-01 00:42:38,955 DEBUG : 0.003s 0.0 bytes 401 GET /api/core/session-time 2021-09-01 00:42:39,424 DEBUG : Initializing WebSocket 2021-09-01 00:42:39,424 DEBUG : Validating WebSocket request 2021-09-01 00:42:39,424 DEBUG : Attempting to upgrade connection 2021-09-01 00:42:39,425 DEBUG : WebSocket request accepted, switching protocols 2021-09-01 00:42:39,425 DEBUG : Spawning sub-Socket Greenlet: send_into_ws 2021-09-01 00:42:39,425 DEBUG : Spawning sub-Socket Greenlet: read_from_ws 2021-09-01 00:42:39,426 DEBUG : Spawning sub-Socket Greenlet: _heartbeat 2021-09-01 00:42:39,426 DEBUG : Spawning sub-Socket Greenlet: _heartbeat_timeout 2021-09-01 00:42:39,631 DEBUG : Socket 139842760711864 connected 2021-09-01 00:42:39,849 DEBUG : ... GET /api/core/tasks/request-update 2021-09-01 00:42:39,850 DEBUG : 0.002s 0.0 bytes 401 GET /api/core/tasks/request-update 2021-09-01 00:42:43,179 DEBUG : ... POST /api/core/auth 2021-09-01 00:42:43,298 INFO : Opening a session for user global-admin 2021-09-01 00:42:43,300 INFO : Opening a new worker gate for session 2, client 10.0.255.1 2021-09-01 00:42:43,303 DEBUG : Invoke target <bound method WorkerGate._target of <aj.gate.gate.WorkerGate object at 0x7f2fae1ad080>> in child process. 2021-09-01 00:42:43,314 DEBUG : _child start. target: <bound method WorkerGate._target of <aj.gate.gate.WorkerGate object at 0x7f2fae1ad080>> 2021-09-01 00:42:43,316 DEBUG : Delete current hub's threadpool. 2021-09-01 00:42:43,317 DEBUG : Destroy hub and default loop. 2021-09-01 00:42:43,317 DEBUG : Created new hub and default event loop. 2021-09-01 00:42:43,319 DEBUG : SIGCHLD watcher for 2211 started. 2021-09-01 00:42:43,320 DEBUG : Invalidate <_GIPCWriter_c45e8c fd: 26> in parent. 2021-09-01 00:42:43,318 DEBUG : Invalidate <_GIPCReader_9e51b3 fd: 9> in child. 2021-09-01 00:42:43,321 DEBUG : Legitimate <_GIPCReader_9e51b3 fd: 9> for current process. 2021-09-01 00:42:43,321 DEBUG : Invalidating <_GIPCReader_9e51b3 fd: 9> ... 2021-09-01 00:42:43,321 DEBUG : Invalidate <_GIPCWriter_84ca5a fd: 15> in child. 2021-09-01 00:42:43,321 DEBUG : Legitimate <_GIPCWriter_84ca5a fd: 15> for current process. 2021-09-01 00:42:43,321 DEBUG : Invalidating <_GIPCWriter_84ca5a fd: 15> ... 2021-09-01 00:42:43,322 DEBUG : Invalidate <_GIPCReader_9f60c0 fd: 25> in child. 2021-09-01 00:42:43,322 DEBUG : Legitimate <_GIPCReader_9f60c0 fd: 25> for current process. 2021-09-01 00:42:43,322 DEBUG : Invalidating <_GIPCReader_9f60c0 fd: 25> ... 2021-09-01 00:42:43,322 DEBUG : Invalidate <_GIPCWriter_149827 fd: 29> in child. 2021-09-01 00:42:43,322 DEBUG : Legitimate <_GIPCWriter_149827 fd: 29> for current process. 2021-09-01 00:42:43,322 DEBUG : Invalidating <_GIPCWriter_149827 fd: 29> ... 2021-09-01 00:42:43,323 DEBUG : Legitimate <_GIPCWriter_c45e8c fd: 26> for current process. 2021-09-01 00:42:43,323 DEBUG : Handle <_GIPCWriter_c45e8c fd: 26> is now valid in child. 2021-09-01 00:42:43,323 DEBUG : Legitimate <_GIPCReader_ac2af2 fd: 28> for current process. 2021-09-01 00:42:43,323 DEBUG : Handle <_GIPCReader_ac2af2 fd: 28> is now valid in child. 2021-09-01 00:42:43,328 DEBUG : Invalidating <_GIPCWriter_c45e8c fd: 26> ... 2021-09-01 00:42:43,328 DEBUG : Invalidate <_GIPCReader_ac2af2 fd: 28> in parent. 2021-09-01 00:42:43,329 DEBUG : Invalidating <_GIPCReader_ac2af2 fd: 28> ... 2021-09-01 00:42:43,329 DEBUG : Started child process 2211 2021-09-01 00:42:43,330 DEBUG : New session 2 2021-09-01 00:42:43,332 DEBUG : 0.158s 45.0 bytes 200 POST /api/core/auth 2021-09-01 00:42:43,333 INFO : New worker "session 2" PID 2211, EUID 0, EGID 0 2021-09-01 00:42:43,334 INFO : Authenticating session as global-admin 2021-09-01 00:42:43,432 DEBUG : Authentication provider "Linux Muster LDAP" maps "global-admin" -> 0 2021-09-01 00:42:43,567 DEBUG : Closed WebSocket 2021-09-01 00:42:43,605 DEBUG : ... GET / 2021-09-01 00:42:43,607 DEBUG : 0.005s 0.0 bytes 302 GET / 2021-09-01 00:42:43,843 DEBUG : ... GET /view/ 2021-09-01 00:42:43,845 DEBUG : 0.004s 11.0 KB 200 GET /view/ 2021-09-01 00:42:44,140 DEBUG : ... GET /resources/all.init.js 2021-09-01 00:42:44,142 DEBUG : ... GET /resources/all.vendor.js 2021-09-01 00:42:44,151 DEBUG : 0.025s 309.0 bytes 200 GET /resources/all.init.js 2021-09-01 00:42:44,345 DEBUG : ... GET /resources/all.css 2021-09-01 00:42:44,346 DEBUG : ... GET /resources/all.vendor.css 2021-09-01 00:42:44,347 DEBUG : ... GET /resources/all.partials.js 2021-09-01 00:42:44,347 DEBUG : 0.211s 645.3 KB 200 GET /resources/all.vendor.js 2021-09-01 00:42:44,348 DEBUG : 0.210s 28.0 KB 200 GET /resources/all.css 2021-09-01 00:42:44,348 DEBUG : 0.209s 6.3 KB 200 GET /resources/all.vendor.css 2021-09-01 00:42:44,373 DEBUG : ... GET /resources/all.js 2021-09-01 00:42:44,373 DEBUG : 0.224s 47.6 KB 200 GET /resources/all.partials.js 2021-09-01 00:42:44,401 DEBUG : 0.251s 56.5 KB 200 GET /resources/all.js 2021-09-01 00:42:45,327 DEBUG : ... GET /resources/all.locale.js 2021-09-01 00:42:45,343 DEBUG : 0.018s 13.3 KB 200 GET /resources/all.locale.js 2021-09-01 00:42:45,344 DEBUG : ... GET /api/core/identity 2021-09-01 00:42:45,382 DEBUG : 0.056s 970.0 bytes 200 GET /api/core/identity 2021-09-01 00:42:45,384 DEBUG : ... GET /api/core/session-time 2021-09-01 00:42:45,384 DEBUG : Sending a session list update to restricted session 2021-09-01 00:42:45,387 DEBUG : Sending a session list update to session 2 2021-09-01 00:42:45,387 DEBUG : ... GET /api/core/sidebar 2021-09-01 00:42:45,389 DEBUG : ... GET /resources/all.locale.js 2021-09-01 00:42:45,389 DEBUG : 0.055s 2.9 KB 200 GET /api/core/sidebar 2021-09-01 00:42:45,391 DEBUG : Received a session list update 2021-09-01 00:42:45,393 DEBUG : ... GET /api/core/sidebar 2021-09-01 00:42:45,394 DEBUG : 0.058s 13.3 KB 200 GET /resources/all.locale.js 2021-09-01 00:42:45,394 DEBUG : 0.052s 2.9 KB 200 GET /api/core/sidebar 2021-09-01 00:42:45,397 DEBUG : Received a session list update 2021-09-01 00:42:45,397 DEBUG : 0.065s 11.0 bytes 200 GET /api/core/session-time 2021-09-01 00:42:45,594 DEBUG : ... GET /api/core/session-time 2021-09-01 00:42:45,601 DEBUG : Sending a session list update to restricted session 2021-09-01 00:42:45,603 DEBUG : Sending a session list update to session 2 2021-09-01 00:42:45,609 DEBUG : Received a session list update 2021-09-01 00:42:45,609 DEBUG : 0.019s 4.0 bytes 200 GET /api/core/session-time 2021-09-01 00:42:45,612 DEBUG : Received a session list update 2021-09-01 00:42:45,627 DEBUG : ... GET /api/core/session-time 2021-09-01 00:42:45,628 DEBUG : Sending a session list update to restricted session 2021-09-01 00:42:45,629 DEBUG : Sending a session list update to session 2 2021-09-01 00:42:45,640 DEBUG : 0.021s 4.0 bytes 200 GET /api/core/session-time 2021-09-01 00:42:45,643 DEBUG : Received a session list update 2021-09-01 00:42:45,645 DEBUG : Received a session list update 2021-09-01 00:42:46,229 DEBUG : ... GET /api/lm/setup-wizard/is-configured 2021-09-01 00:42:46,231 DEBUG : 0.004s 4.0 bytes 200 GET /api/lm/setup-wizard/is-configured 2021-09-01 00:42:46,244 DEBUG : ... GET /api/lmn/quota/global-admin 2021-09-01 00:42:46,247 DEBUG : Popen: ['sophomorix-query', '--sam', 'global-admin', '--user-full', '--quota-usage', '-jj'] 2021-09-01 00:42:46,491 DEBUG : Initializing WebSocket 2021-09-01 00:42:46,492 DEBUG : Validating WebSocket request 2021-09-01 00:42:46,492 DEBUG : Attempting to upgrade connection 2021-09-01 00:42:46,493 DEBUG : WebSocket request accepted, switching protocols 2021-09-01 00:42:46,494 DEBUG : Spawning sub-Socket Greenlet: send_into_ws 2021-09-01 00:42:46,494 DEBUG : Spawning sub-Socket Greenlet: read_from_ws 2021-09-01 00:42:46,495 DEBUG : Spawning sub-Socket Greenlet: _heartbeat 2021-09-01 00:42:46,495 DEBUG : Spawning sub-Socket Greenlet: _heartbeat_timeout 2021-09-01 00:42:46,726 DEBUG : Socket 139842760882664 connected 2021-09-01 00:42:46,728 DEBUG : Socket namespace 139842760882664 created 2021-09-01 00:42:46,728 DEBUG : Spawning sub-Socket Greenlet (in a namespace): _reader 2021-09-01 00:42:46,956 DEBUG : ... GET /api/core/tasks/request-update 2021-09-01 00:42:46,957 DEBUG : 0.003s 4.0 bytes 200 GET /api/core/tasks/request-update 2021-09-01 00:42:47,202 DEBUG : 0.969s 4.9 KB 200 GET /api/lmn/quota/global-admin 2021-09-01 00:42:50,878 DEBUG : ... GET /api/core/session-time 2021-09-01 00:42:50,879 DEBUG : Sending a session list update to restricted session 2021-09-01 00:42:50,880 DEBUG : Sending a session list update to session 2 2021-09-01 00:42:50,880 DEBUG : Received a session list update 2021-09-01 00:42:50,881 DEBUG : Received a session list update 2021-09-01 00:42:50,890 DEBUG : 0.014s 4.0 bytes 200 GET /api/core/session-time 2021-09-01 00:42:50,896 DEBUG : ... GET /api/lm/schoolsettings 2021-09-01 00:42:50,900 DEBUG : 0.007s 1.7 KB 200 GET /api/lm/schoolsettings 2021-09-01 00:42:51,243 DEBUG : ... POST /api/lmn/schoolsettings/determine-encoding 2021-09-01 00:42:51,252 DEBUG : Popen: ['sophomorix-check', '--analyze-encoding', '/etc/linuxmuster/sophomorix/default-school/students.csv', '-jj'] 2021-09-01 00:42:51,262 DEBUG : ... GET /api/lm/users/students-list 2021-09-01 00:42:51,286 INFO : Detected encoding for /etc/linuxmuster/sophomorix/default-school/students.csv : utf-8 2021-09-01 00:42:51,300 INFO : Detected encoding for /etc/linuxmuster/sophomorix/default-school/students.csv : utf-8 2021-09-01 00:42:51,319 DEBUG : 0.073s 102.5 KB 200 GET /api/lm/users/students-list 2021-09-01 00:42:52,555 DEBUG : 1.320s 6.0 bytes 200 POST /api/lmn/schoolsettings/determine-encoding 2021-09-01 00:43:30,646 DEBUG : heartbeat timed out, killing socket 2021-09-01 00:43:30,646 DEBUG : Calling disconnect() on sessid='8831366497474853' client_queue[2] server_queue[1] hits=1 2021-09-01 00:43:30,646 DEBUG : Socket 139842761078096 disconnected 2021-09-01 00:43:30,647 DEBUG : Removing sessid='8831366497474853' client_queue[2] hits=1 from server sockets 2021-09-01 00:43:39,634 DEBUG : heartbeat timed out, killing socket 2021-09-01 00:43:39,635 DEBUG : Calling disconnect() on sessid='09341361703776141' client_queue[2] server_queue[1] hits=1 2021-09-01 00:43:39,635 DEBUG : Socket 139842760711864 disconnected 2021-09-01 00:43:39,635 DEBUG : Removing sessid='09341361703776141' client_queue[2] server_queue[1] hits=1 from server sockets

kiarn commented 3 years ago

Unfortunately it's not better with debug mode : we can see the HTTP 500 but not the reason.

Another possibility is to launch the webui per Hand, but first change the systemd file config back to the previous version, and then run a 

systemctl daemon-reload
systemctl stop linuxmuster-webui.service

and then : 

python3 /usr/local/bin/ajenti-panel --dev --stock-plugins --plugins /usr/lib/linuxmuster-webui/plugins

When the error is thrown, you can stop it with Ctrl - C and then restart the systemd service. Hopefully we will know what is going on : I will have a look at this tomorrow.

delacroix0815 commented 3 years ago

Finally :)

01.09.2021 01:05 [worker 2589] gate.py:120 DEBUG ... GET / 01.09.2021 01:05 [master 2574] middleware.py:250 DEBUG 0.009s 0.0 bytes 302 GET / 01.09.2021 01:05 [worker 2589] gate.py:120 DEBUG ... GET /view/ 01.09.2021 01:05 [worker 2589] gate.py:120 DEBUG Building resources in /usr/lib/linuxmuster-webui/plugins 01.09.2021 01:05 [worker 2589] gate.py:120 DEBUG Popen: ['ajenti-dev-multitool', '--build'] 01.09.2021 01:05 [worker 2589] gate.py:120 ERROR Unhandled endpoint error at /view/ Traceback (most recent call last): File "/usr/local/lib/python3.6/dist-packages/aj/api/endpoint.py", line 71, in wrapper result = fx(self, context, *args, kwargs) File "/usr/local/lib/python3.6/dist-packages/ajenti_plugin_core/views/main.py", line 48, in handle_view stderr=subprocess.PIPE File "/usr/local/lib/python3.6/dist-packages/aj/compat.py", line 25, in Popen args, kwargs) File "/usr/local/lib/python3.6/dist-packages/gevent/subprocess.py", line 619, in init restore_signals, start_new_session) File "/usr/local/lib/python3.6/dist-packages/gevent/subprocess.py", line 1491, in _execute_child raise child_exception FileNotFoundError: [Errno 2] Datei oder Verzeichnis nicht gefunden: 'ajenti-dev-multitool' Traceback (most recent call last): File "/usr/local/lib/python3.6/dist-packages/aj/routing.py", line 92, in handle output = instance.handle(http_context) File "/usr/local/lib/python3.6/dist-packages/aj/api/http.py", line 84, in handle data = method(http_context, http_context.route_data) File "/usr/local/lib/python3.6/dist-packages/aj/api/endpoint.py", line 71, in wrapper result = fx(self, context, args, kwargs) File "/usr/local/lib/python3.6/dist-packages/ajenti_plugin_core/views/main.py", line 48, in handle_view stderr=subprocess.PIPE File "/usr/local/lib/python3.6/dist-packages/aj/compat.py", line 25, in Popen *args, **kwargs) File "/usr/local/lib/python3.6/dist-packages/gevent/subprocess.py", line 619, in init restore_signals, start_new_session) File "/usr/local/lib/python3.6/dist-packages/gevent/subprocess.py", line 1491, in _execute_child raise child_exception FileNotFoundError: [Errno 2] Datei oder Verzeichnis nicht gefunden: 'ajenti-dev-multitool' 01.09.2021 01:05 [master 2574] middleware.py:250 DEBUG 0.111s 6.4 KB 500 GET /view/ Socket is dead Traceback (most recent call last): File "/usr/local/lib/python3.6/dist-packages/geventwebsocket/websocket.py", line 344, in send self.send_frame(message, opcode) File "/usr/local/lib/python3.6/dist-packages/geventwebsocket/websocket.py", line 318, in send_frame raise WebSocketError(MSG_ALREADY_CLOSED) geventwebsocket.exceptions.WebSocketError: Connection is already closed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "src/gevent/greenlet.py", line 716, in gevent._greenlet.Greenlet.run File "/usr/local/lib/python3.6/dist-packages/socketio/transports.py", line 251, in send_into_ws websocket.send(message) File "/usr/local/lib/python3.6/dist-packages/geventwebsocket/websocket.py", line 347, in send raise WebSocketError(MSG_SOCKET_DEAD) geventwebsocket.exceptions.WebSocketError: Socket is dead 2021-08-31T23:05:57Z <Greenlet "Greenlet-0" at 0x7f6ef3e3fe48: send_into_ws> failed with WebSocketError

Socket is dead Traceback (most recent call last): File "/usr/local/lib/python3.6/dist-packages/geventwebsocket/websocket.py", line 344, in send self.send_frame(message, opcode) File "/usr/local/lib/python3.6/dist-packages/geventwebsocket/websocket.py", line 318, in send_frame raise WebSocketError(MSG_ALREADY_CLOSED) geventwebsocket.exceptions.WebSocketError: Connection is already closed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "src/gevent/greenlet.py", line 716, in gevent._greenlet.Greenlet.run File "/usr/local/lib/python3.6/dist-packages/socketio/transports.py", line 251, in send_into_ws websocket.send(message) File "/usr/local/lib/python3.6/dist-packages/geventwebsocket/websocket.py", line 347, in send raise WebSocketError(MSG_SOCKET_DEAD) geventwebsocket.exceptions.WebSocketError: Socket is dead 2021-08-31T23:06:00Z <Greenlet "Greenlet-1" at 0x7f6eee3f6b48: send_into_ws> failed with WebSocketError

kiarn commented 3 years ago

Thanks for your effort, but that's not the error we are looking for, it just says that a development tool is missing, what is normal on your machine. Installing this tool is not a solution because you will missing dozen of dependencies to compile the files.

I will test on another of my servers today and see if I find a better solution to debug.

kiarn commented 3 years ago

I don't find a simple way to debug this actually, so I ask some others questions to try to understand the situation :

1) Does the file /etc/linuxmuster/sophomorix/default-school/school.conf has the right permissions ? 2) Is there some duplicate entries in ? 3) Is there any error in the web developer console of the browser ? 4) Can you please run sophomorix-user -u createc -iv | grep schoolsettings and post the result here ?

Arnaud

delacroix0815 commented 3 years ago
  1. -rw-r--r-- 1 root root 1,7K Feb 7 2021 /etc/linuxmuster/sophomorix/default-school/school.conf
  2. Contains duplicates like QUOTA_DEFAULT_GLOBAL, but in different sections for the [role.students|teacher|schooladmins], so i guess this is ok
  3. didn't check that because i dunno what to look for
  4. output for "sophomorix-user -u createc -iv | grep -i schoolsettings" was empty, i then did "sophomorix-user -u global-admin -iv | grep -i schoolsettings" and i got those 2: lm:schoolsettings: true sidebar:view:/view/lm/schoolsettings: true

For createc, both values aren't "false", they simply do not exist.

kiarn commented 3 years ago
  1. didn't check that because i dunno what to look for

In your browser, for example chrome, with F12 you can acces a web developer console. Errors are shown in the tab Console.

  1. output for "sophomorix-user -u createc -iv | grep -i schoolsettings" was empty, i then did "sophomorix-user -u global-admin -iv | grep -i schoolsettings" and i got those 2: lm:schoolsettings: true sidebar:view:/view/lm/schoolsettings: true

For createc, both values aren't "false", they simply do not exist.

It could be ok, it depends which version of the webui you are using : stable or testing ? ( with your description, it should be stable ). You can also post the result of dpkg -l | grep webui.

Arnaud

delacroix0815 commented 3 years ago

root@server:~# dpkg -l | grep webui ii linuxmuster-webui7 1.0.156-1 all next generation web-based management tool for linuxmuster.net v7.x

kiarn commented 3 years ago

Ok, I found out why I was not able to reproduce the issue.

To solve this please edit /usr/lib/linuxmuster-webui/etc/default-ui-permissions.ini and add the following line in the [schooladmin] section : 

    WEBUI_PERMISSIONS=lm:schoolsettings: true

Then run sophomorix-ui, and the user must logout / login in the Webui.

delacroix0815 commented 3 years ago

Thank you, adding the line and running sophomorix-ui worked! Do you know why this wasn't included in the .ini in the first place?

kiarn commented 3 years ago

Maybe this was forgotten, I really don't know, but it's corrected in testing since a long time. Glad I was able to help, even if it was a long way.