Problem:UCS@school - Import ServerError: Received status_code=502 with reason='Proxy Error'

Knowledge Base Community
, , , ,
1

Problem

It is not possible to successfully complete an import for students via the UMC. Instead, the following error occurs and you receive this traceback.

Bildschirmfoto-UCS
Bildschirmfoto-UCS1497×884 73.8 KB

Interner Server-Fehler in "schoolimport/dry-run/progress".
Request: schoolimport/dry-run/progress

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/univention/management/console/base.py", line 387, in __error_handling
    six.reraise(etype, exc, etraceback)
  File "/usr/lib/python3/dist-packages/six.py", line 693, in reraise
    raise value
  File "/usr/lib/python3/dist-packages/univention/management/console/base.py", line 285, in execute
    function.__func__(self, request, *args, **kwargs)
  File "/usr/lib/python3/dist-packages/univention/management/console/modules/decorators.py", line 805, in _decorated
    return function(self, request, *args, **kwargs)
  File "/usr/lib/python3/dist-packages/univention/management/console/modules/decorators.py", line 478, in _response
    result = _multi_response(self, request)
  File "/usr/lib/python3/dist-packages/univention/management/console/modules/decorators.py", line 189, in _response
    return function(self, request)
  File "/usr/lib/python3/dist-packages/univention/management/console/modules/decorators.py", line 602, in _response
    return list(function(self, iterator, *nones))
  File "/usr/lib/python3/dist-packages/univention/management/console/modules/decorators.py", line 444, in _fake_func
    yield function(self, *args)
  File "/usr/lib/python3/dist-packages/univention/management/console/modules/schoolimport/__init__.py", line 245, in poll_dry_run
    return progress.poll()
  File "/usr/lib/python3/dist-packages/univention/management/console/modules/mixins.py", line 105, in poll
    six.reraise(*self.exc_info)
  File "/usr/lib/python3/dist-packages/six.py", line 692, in reraise
    raise value.with_traceback(tb)
ucsschool.http_api.client.ServerError: Received status_code=502 with reason='Proxy Error' for requests.post(**url='https://ucs01.univention-schule.de/api/v1/imports/users/', data={'dryrun': True, 'school': 'https://ucs01.univention-schule.de/api/v1/schools/UniventionUCS/', 'user_role': 'student'}, files={'input_file': 'Univention-Schüler-Import.csv'}, params=None, auth=('admin-import', '****************'), headers={'Accept': 'application/json'}, verify=False).

Solution

In my case the auth user admin-import showing in the traceback was missing in the rabbitmq, so the user don’t have the authorization to perfom the import.
params=None, auth=('admin-import', '****************')

To get the user admin-import into the rabbitmq db you could use the following join-script, in my case that solve the issue.

univention-run-join-scripts --run-scripts 40ucs-school-import-http-api.inst --force

If the join-script failed, check the status and whether if the RabbitMQ-Server is running.

systemctl status rabbitmq-server.service

You will also get more informations in the less /var/log/rabbitmq/rabbit@master.log

Log file(s) (may contain more information):
   /var/log/rabbitmq/rabbit@master.log
   /var/log/rabbitmq/rabbit@master_upgrade.log
2025-03-12 11:38:51.114 [info] <0.8.0> Log file opened with Lager
2025-03-12 11:38:51.900 [info] <0.8.0> Feature flags: list of feature flags found:
2025-03-12 11:38:51.900 [info] <0.8.0> Feature flags:   [ ] implicit_default_bindings
2025-03-12 11:38:51.900 [info] <0.8.0> Feature flags:   [ ] quorum_queue
2025-03-12 11:38:51.900 [info] <0.8.0> Feature flags:   [ ] virtual_host_metadata
2025-03-12 11:38:51.900 [info] <0.8.0> Feature flags: feature flag states written to disk: yes
2025-03-12 11:38:51.945 [info] <0.315.0> ra: meta data store initialised. 0 record(s) recovered
2025-03-12 11:38:51.945 [info] <0.320.0> WAL: recovering ["/var/lib/rabbitmq/mnesia/rabbit@master/quorum/rabbit@master/00000031.wal"]
2025-03-12 11:38:51.945 [error] <0.320.0> CRASH REPORT Process <0.320.0> with 0 neighbours exited with reason: no case clause matching {ok,<<>>} in ra_log_wal:open_existing/1 line 646 in gen_batch_server:init_it
/6 line 165

RabbitMQ crashes because the write-ahead log (WAL) file is corrupted.

CRASH REPORT Process <0.320.0> with 0 neighbours exited with reason: no case clause matching {ok,<<>>} in ra_log_wal:open_existing/1 line 646 shows that RabbitMQ encountered an unexpected state while trying to load the WAL file (/var/lib/rabbitmq/mnesia/rabbit@master/quorum/rabbit@master/00000031.wal).

Reset WAL files to delete the corrupted WAL files and get RabbitMQ running again.

  1. rm -rf /var/lib/rabbitmq/mnesia/rabbit@master/quorum/rabbit@master/*
  2. systemctl start rabbitmq-server
  3. systemctl status rabbitmq-server
  4. rabbitmqctl status

rabbitmqctl status output:

Status of node rabbit@master ...

ESC[1mRuntimeESC[0m


OS PID: 30514

OS: Linux

Uptime (seconds): 2489

RabbitMQ version: 3.8.2

Node name: rabbit@master

Erlang configuration: Erlang/OTP 22 [erts-10.6.4] [source] [64-bit] [smp:4:4] [ds:4:4:10] [async-threads:64]

Erlang processes: 357 used, 1048576 limit

Scheduler run queue: 1

Cluster heartbeat timeout (net_ticktime): 60


ESC[1mPluginsESC[0m


Enabled plugin file: /etc/rabbitmq/enabled_plugins

Enabled plugins:



ESC[1mData directoryESC[0m


Node data directory: /var/lib/rabbitmq/mnesia/rabbit@master


ESC[1mConfig filesESC[0m


 * /etc/rabbitmq/rabbitmq.config


ESC[1mLog file(s)ESC[0m


 * /var/log/rabbitmq/rabbit@master.log

 * /var/log/rabbitmq/rabbit@master_upgrade.log


ESC[1mAlarmsESC[0m


(none)


ESC[1mMemoryESC[0m


Calculation strategy: rss

Memory high watermark setting: 0.4 of available memory, computed to: 6.711 gb

code: 0.0268 gb (26.51 %)

other_proc: 0.0238 gb (23.59 %)

reserved_unallocated: 0.0152 gb (15.07 %)

other_system: 0.0127 gb (12.54 %)

binary: 0.0106 gb (10.51 %)

allocated_unused: 0.0062 gb (6.18 %)

other_ets: 0.0027 gb (2.67 %)

atom: 0.0014 gb (1.42 %)

connection_other: 0.0005 gb (0.48 %)

queue_procs: 0.0004 gb (0.36 %)

metrics: 0.0002 gb (0.21 %)

connection_channels: 0.0001 gb (0.13 %)

mnesia: 0.0001 gb (0.1 %)

connection_readers: 0.0001 gb (0.09 %)

msg_index: 0.0001 gb (0.06 %)

connection_writers: 0.0 gb (0.05 %)

quorum_ets: 0.0 gb (0.04 %)

plugins: 0.0 gb (0.01 %)

mgmt_db: 0.0 gb (0.0 %)

queue_slave_procs: 0.0 gb (0.0 %)

quorum_queue_procs: 0.0 gb (0.0 %)


ESC[1mFile DescriptorsESC[0m


Total: 10, limit: 65439

Sockets: 4, limit: 58893


ESC[1mFree Disk SpaceESC[0m


Low free disk space watermark: 0.05 gb

Free disk space: 193.0677 gb


ESC[1mTotalsESC[0m


Connection count: 4

Queue count: 6

Virtual host count: 2


ESC[1mListenersESC[0m


Interface: [::], port: 25672, protocol: clustering, purpose: inter-node and CLI tool communication

Interface: 127.0.0.1, port: 5672, protocol: amqp, purpose: AMQP 0-9-1 and AMQP 1.0

Interface: [::1], port: 5672, protocol: amqp, purpose: AMQP 0-9-1 and AMQP 1.0

systemctl status rabbitmq-server.service 

● rabbitmq-server.service - RabbitMQ Messaging Server
   Loaded: loaded (/lib/systemd/system/rabbitmq-server.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2025-03-12 12:07:13 CET; 40min ago
 Main PID: 30514 (beam.smp)
   Status: "Initialized"
    Tasks: 91 (limit: 4915)
   Memory: 93.3M
   CGroup: /system.slice/rabbitmq-server.service
           ├─30510 /bin/sh /usr/sbin/rabbitmq-server
           ├─30514 /usr/lib/erlang/erts-10.6.4/bin/beam.smp -W w -A 64 -MBas ageffcbf -MHas ageffcbf -MBlmbcs 512 -MHlmbcs 512 -MMmcs 30 -P 1048576 -t 5000000 -stbt db -zdbbl 128000 -K true -- -root /usr/lib/erl
           ├─30789 erl_child_setup 65536
           ├─30847 inet_gethost 4
           └─30848 inet_gethost 4

Mär 12 12:07:13 master systemd[1]: rabbitmq-server.service: Supervising process 30514 which is not our child. We'll most likely not notice when it exits.
Mär 12 12:07:13 master systemd[1]: Started RabbitMQ Messaging Server.
Mär 12 12:08:21 master systemd[1]: rabbitmq-server.service: Supervising process 30514 which is not our child. We'll most likely not notice when it exits.
Mär 12 12:08:21 master systemd[1]: rabbitmq-server.service: Supervising process 30514 which is not our child. We'll most likely not notice when it exits.
Mär 12 12:08:21 master systemd[1]: rabbitmq-server.service: Supervising process 30514 which is not our child. We'll most likely not notice when it exits.
Mär 12 12:08:21 master systemd[1]: rabbitmq-server.service: Supervising process 30514 which is not our child. We'll most likely not notice when it exits.
Mär 12 12:08:21 master systemd[1]: rabbitmq-server.service: Supervising process 30514 which is not our child. We'll most likely not notice when it exits.
Mär 12 12:08:21 master systemd[1]: rabbitmq-server.service: Supervising process 30514 which is not our child. We'll most likely not notice when it exits.
Mär 12 12:08:22 master systemd[1]: rabbitmq-server.service: Supervising process 30514 which is not our child. We'll most likely not notice when it exits.
Mär 12 12:08:22 master systemd[1]: rabbitmq-server.service: Supervising process 30514 which is not our child. We'll most likely not notice when it exits.
lines 1-24/24 (END)

Investigation

Check the status of services for the import and if necessary, restart them.

  1. systemctl status apache2.service ucs-school-import-http-api.service postgresql.service rabbitmq-server.service

  2. systemctl restart apache2.service ucs-school-import-http-api.service postgresql.service rabbitmq-server.service

See also:

In my case, the service for the rabbitmq was not running and would not start correctly, because the permissions from the rabbitmq dir was not set correct, like shown in the following outputs.

root@dc0:~/univention-support# systemctl status rabbitmq-server.service
● rabbitmq-server.service - RabbitMQ Messaging Server
   Loaded: loaded (/lib/systemd/system/rabbitmq-server.service; enabled; vendor preset: enabled)
   Active: activating (auto-restart) (Result: exit-code) since Thu 2024-09-26 05:04:24 CEST; 6s ago
  Process: 497 ExecStart=/usr/sbin/rabbitmq-server (code=exited, status=200/CHDIR)
 Main PID: 497 (code=exited, status=200/CHDIR)

root@dc0:~/univention-support# ls -lah /var/lib/rabbitmq/
insgesamt 16K
dr--r--r--  3 rabbitmq rabbitmq 4,0K Jun 24  2022 .
drwxr-xr-x 86 root     root     4,0K Sep  4 20:55 ..
-r--------  1 rabbitmq rabbitmq   20 Jun 24  2022 .erlang.cookie
dr--r-----  4 rabbitmq rabbitmq 4,0K Sep 19 15:55 mnesia

I was able to get the service running again by setting the correct permissions under /var/lib/rabbitmq/ and running a diagnostic rabbitmq-diagnostics status.

  1. chmod -R 750 /var/lib/rabbitmq/
  2. chmod 100 /var/lib/rabbitmq/.erlang.cookie
root@dc0:~/univention-support# ls -lah /var/lib/rabbitmq/
insgesamt 16K
drwxr-x---  3 rabbitmq rabbitmq 4,0K Jun 24  2022 .
drwxr-xr-x 86 root     root     4,0K Sep  4 20:55 ..
-r--------  1 rabbitmq rabbitmq   20 Jun 24  2022 .erlang.cookie
drwxr-x---  4 rabbitmq rabbitmq 4,0K Sep 26 05:14 mnesia
  1. rabbitmq-diagnostics status
root@dc0:~/univention-support# rabbitmq-diagnostics status
Status of node rabbit@dc0 ...  
Runtime

OS PID: 8637
OS: Linux
Uptime (seconds): 13
RabbitMQ version: 3.8.2
Node name: rabbit@dc0
Erlang configuration: Erlang/OTP 22 [erts-10.6.4] [source] [64-bit] [smp:2:2] [ds:2:2:10] [async-threads:64]
Erlang processes: 286 used, 1048576 limit
Scheduler run queue: 1
Cluster heartbeat timeout (net_ticktime): 60

Plugins

Enabled plugin file: /etc/rabbitmq/enabled_plugins
Enabled plugins:


Data directory

Node data directory: /var/lib/rabbitmq/mnesia/rabbit@dc0

Config files

 * /etc/rabbitmq/rabbitmq.config

Log file(s)

 * /var/log/rabbitmq/rabbit@dc0.log
 * /var/log/rabbitmq/rabbit@dc0_upgrade.log

Alarms

(none)

Memory

Calculation strategy: rss
Memory high watermark setting: 0.4 of available memory, computed to: 3.334 gb
other_proc: 0.0273 gb (29.56 %)
code: 0.0268 gb (29.03 %)
reserved_unallocated: 0.0134 gb (14.58 %)
other_system: 0.0116 gb (12.59 %)
allocated_unused: 0.0085 gb (9.19 %)
other_ets: 0.0027 gb (2.91 %)  
atom: 0.0014 gb (1.56 %)
metrics: 0.0002 gb (0.21 %)
binary: 0.0001 gb (0.11 %)
mnesia: 0.0001 gb (0.1 %)
msg_index: 0.0001 gb (0.06 %)  
queue_procs: 0.0 gb (0.05 %)   
quorum_ets: 0.0 gb (0.05 %)
plugins: 0.0 gb (0.01 %)
connection_channels: 0.0 gb (0.0 %)
connection_other: 0.0 gb (0.0 %)
connection_readers: 0.0 gb (0.0 %)
connection_writers: 0.0 gb (0.0 %)
mgmt_db: 0.0 gb (0.0 %)
queue_slave_procs: 0.0 gb (0.0 %)
quorum_queue_procs: 0.0 gb (0.0 %)

File Descriptors

Total: 6, limit: 65439
Sockets: 0, limit: 58893

Free Disk Space

Low free disk space watermark: 0.05 gb
Free disk space: 19.6606 gb

Totals

Connection count: 0
Queue count: 2
Virtual host count: 2

Listeners

Interface: [::], port: 25672, protocol: clustering, purpose: inter-node and CLI tool communication
Interface: 127.0.0.1, port: 5672, protocol: amqp, purpose: AMQP 0-9-1 and AMQP 1.0
Interface: [::1], port: 5672, protocol: amqp, purpose: AMQP 0-9-1 and AMQP 1.0
  1. systemctl stop rabbitmq-server.service
  2. systemctl start rabbitmq-server.service
  3. systemctl status rabbitmq-server.service
root@dc0:~/univention-support# systemctl status rabbitmq-server.service
● rabbitmq-server.service - RabbitMQ Messaging Server
   Loaded: loaded (/lib/systemd/system/rabbitmq-server.service; enabled; vendor preset: enabled)
   Active: active (running) since Thu 2024-09-26 05:21:37 CEST; 11s ago
 Main PID: 10250 (beam.smp)
   Status: "Initialized"
    Tasks: 87 (limit: 4915)
   Memory: 76.1M
   CGroup: /system.slice/rabbitmq-server.service
           ├─10246 /bin/sh /usr/sbin/rabbitmq-server
           ├─10250 /usr/lib/erlang/erts-10.6.4/bin/beam.smp -W w -A 64 -MBas ageffcbf -MHas ageffcbf -MBlmbcs 512 -MHlmbcs 512 -MMmcs 30 -P 1048576 -t 5000000 -stbt db -zdbbl 128000 -K true -- -root /usr/lib/erl
           ├─10507 erl_child_setup 65536
           ├─10553 inet_gethost 4
           └─10554 inet_gethost 4

Sep 26 05:21:30 dc0 systemd[1]: Starting RabbitMQ Messaging Server...
Sep 26 05:21:37 dc0 systemd[1]: rabbitmq-server.service: Supervising process 10250 which is not our child. We'll most likely not notice when it exits.
Sep 26 05:21:37 dc0 systemd[1]: Started RabbitMQ Messaging Server.