dcm4chee-arc-light, user interface, "Error 400 Bad request"

[LeoGut]

Hello!

On dcm4chee-arc-light User interface, I am getting "Error 400 Bad request" message whenever I try to reject or delete a study or Instance.

The request message I get is this:

1. Request URL:
   https://my.domain/dcm4chee-arc/aets/myaetname/rs/studies/<study_ID>/series/<series_ID>/instances/<Instance_ID>/reject/113039%5EDCM
2. Request Method:
   POST
3. Status Code:
   400 Bad Request
4. Remote Address:
   <my_IP>:443
5. Referrer Policy:
   strict-origin-when-cross-origin

-----------------------------------------------------------------------------------------------------------------------------------
Some things I have done to get this far:

Installed dcm4chee-arc-light using this guide:
https://github.com/dcm4che/dcm4chee-arc-light/wiki/Run-secured-archive-services-and-Elastic-Stack-on-a-single-host

These are the running versions:

- dcm4che/keycloak-gatekeeper:10.0.1

- docker.elastic.co/kibana/kibana:7.10.1

- dcm4che/dcm4chee-arc-psql:5.23.2-secure

- dcm4che/postgres-dcm4chee:13.1-23

- dcm4che/keycloak:11.0.3

- dcm4che/slapd-dcm4chee:2.4.57-23.2

- dcm4che/logstash-dcm4chee:7.10.1-11

- docker.elastic.co/elasticsearch/elasticsearch:7.10.1

I have created a new/custom AET:
https://github.com/dcm4che/dcm4chee-arc-light/wiki/AE-Title(s)-of-the-Archive

Also edited the device extension to be able to use WADO and preview the images:
https://groups.google.com/g/dcm4che/c/fEO3OWMMN_A

All the services are behind a reverse-proxy, similar to this old post:
https://groups.google.com/g/dcm4che/c/OnBjQZYaURM/m/CAkC-441AQAJ

-----------------------------------------------------------------------------------------------------------------------------------

I am not sure if some configuration is missing on my arc-ui, or if it is caused by something on keycloak or even the reverse-proxy.

Any ideas?

[LeoGut]

I also noticed this from the browser console:

Something went wrong on getting base url from a dicom network connections

> TypeError: Cannot read property 'filter' of undefined

    at Function.getBaseUrlFromDicomNetworkConnection (1-es2015.a53d2dffaa0098d36a41.js:3)

    at Function.getUrlFromDcmWebApplication (1-es2015.a53d2dffaa0098d36a41.js:3)

    at e.getDicomURL (1-es2015.a53d2dffaa0098d36a41.js:2)

    at e.studyURL (1-es2015.a53d2dffaa0098d36a41.js:2)

    at e.seriesURL (1-es2015.a53d2dffaa0098d36a41.js:2)

    at e.instanceURL (1-es2015.a53d2dffaa0098d36a41.js:2)

    at i.project (1-es2015.a53d2dffaa0098d36a41.js:2)

    at i._next (main-es2015.613485508861b5ff5a1e.js:1)

    at i.next (main-es2015.613485508861b5ff5a1e.js:1)

    at e._subscribe (main-es2015.613485508861b5ff5a1e.js:1)

[Vrinda Nayak]

What do you see in Browser -> Inspect -> Network -> Response (of the triggered request). Alternatively, please check also the server.log

[LeoGut]

I am not sure if my reply was sent, so I'll post this again and add something I managed to do:

1) From the browser inspector, I got the information written in number 1. related to the reject choice "113039%5EDCM"


2) From my reverse-proxy (nginx):

"GET /dcm4chee-arc/aets/<custom.AET>/rs/studies/<study.ID>/series/<series.ID>/instances?limit=21&includefield=all&offset=0&PatientID=<test.ID>&orderby=InstanceNumber HTTP/1.1" 200 7344 "https://<dns>/dcm4chee-arc/ui2/"

"POST /dcm4chee-arc/aets/<custom.AET>/rs/studies/<study.ID>/series/<series.ID>/instances/<instance.ID>/reject/113039%5EDCM HTTP/1.1" 400 0 "https://<dns>/dcm4chee-arc/ui2/" 

"POST /auth/realms/dcm4che/protocol/openid-connect/token HTTP/1.1" 200 2312 "https://<dns>/"

3) From arc container log: /opt/wildfly/standalone/log/server.log

INFO [org.dcm4chee.arc.qido.QidoRS] (default task-27) Process GET /dcm4chee-arc/aets/<customAET>/rs/studies/<study.ID>/series/<series.ID>/instances?limit=21&includefield=all&offset=0&PatientID=<test.ID>&orderby=InstanceNumber from <docker.container.ID>@<docker.network.arc.subnet.IP>

INFO  [org.dcm4chee.arc.qido.QidoRS] (default task-27) SearchForStudySeriesInstances: 2 Matches

WARN  [io.jaegertracing.internal.reporters.RemoteReporter] (jaeger.RemoteReporter-QueueProcessor) FlushCommand execution failed! Repeated errors of this command will not be logged.: io.jaegertracing.internal.exceptions.SenderException: Failed to flush spans.

at io.jaegertr...@1.5.0//io.jaegertracing.thrift.internal.senders.ThriftSender.flush(ThriftSender.java:115)

at io.jaegertr...@1.5.0//io.jaegertracing.internal.reporters.RemoteReporter$FlushCommand.execute(RemoteReporter.java:160)

at io.jaegertr...@1.5.0//io.jaegertracing.internal.reporters.RemoteReporter$QueueProcessor.run(RemoteReporter.java:182)

at java.base/java.lang.Thread.run(Thread.java:834)

Caused by: io.jaegertracing.internal.exceptions.SenderException: Could not send 1 spans

at io.jaegertr...@1.5.0//io.jaegertracing.thrift.internal.senders.UdpSender.send(UdpSender.java:85)

at io.jaegertr...@1.5.0//io.jaegertracing.thrift.internal.senders.ThriftSender.flush(ThriftSender.java:113)

... 3 more

Caused by: org.apache.thrift.transport.TTransportException: Cannot flush closed transport

at io.jaegertr...@1.5.0//io.jaegertracing.thrift.internal.reporters.protocols.ThriftUdpTransport.flush(ThriftUdpTransport.java:148)

at org.apac...@0.13.0//org.apache.thrift.TServiceClient.sendBase(TServiceClient.java:73)

at org.apac...@0.13.0//org.apache.thrift.TServiceClient.sendBaseOneway(TServiceClient.java:66)

at io.jaegertr...@1.5.0//io.jaegertracing.agent.thrift.Agent$Client.send_emitBatch(Agent.java:70)

at io.jaegertr...@1.5.0//io.jaegertracing.agent.thrift.Agent$Client.emitBatch(Agent.java:63)

at io.jaegertr...@1.5.0//io.jaegertracing.thrift.internal.senders.UdpSender.send(UdpSender.java:83)

... 4 more

Caused by: java.net.PortUnreachableException: ICMP Port Unreachable

at java.base/java.net.PlainDatagramSocketImpl.send(Native Method)

at java.base/java.net.DatagramSocket.send(DatagramSocket.java:695)

at io.jaegertr...@1.5.0//io.jaegertracing.thrift.internal.reporters.protocols.ThriftUdpTransport.flush(ThriftUdpTransport.java:146)

... 9 more

INFO  [io.jaegertracing.internal.reporters.RemoteReporter] (jaeger.RemoteReporter-QueueProcessor) FlushCommand is working again!

----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

4) I managed to reject/delete a study using a curl command from inside arc container

$ docker exec -it arc /bin/bash

I copied the auth token from the browser and used a curl that looked like this:

curl --location --request POST 'https://localhost:8443/dcm4chee-arc/aets/<custom.AET>/rs/studies/<study.ID>/series/<series.ID>/instances/<instance.ID>/reject/113039%5EDCM' \

--header 'Authorization: Bearer <token>'

* I do not remember now, but i think also included a "--insecure" and "-v" on the command.

So, it worked fine from inside the container, I suspect the request gets rejected somewhere from the browser to the service.
I do not know how to test where it happens, keycloak, reverse-proxy, server's firewall(?).
I also suspect it could be related to the certificate, I am using this ENV on arc:

-e DISABLE_TRUST_MANAGER=true
Could the absence of a valid certificate be blocking the request?

[LeoGut]

The browser returns an empty Response with these headers:

HTTP/1.1 400 Bad Request

Server: nginx/1.19.10

Date: Mon, 23 Aug 2021 20:01:48 GMT

Content-Length: 0

Connection: keep-alive

Unlike other requests like WADO_URI and QUIDO_RS. 

Should I configure a new AET just for deletion?

[Vrinda Nayak]

You may ignore the jaegertracing warning messages in archive server log. Perhaps, you're using an archive version older than 5.23.3. See the related issue.

As the rejection service works with curl, please check the exact request (for rejecting instance) received by the archive in the server.log

13:58:08,586 INFO  [org.dcm4chee.arc.iocm.rs.IocmRS] (default task-2) Process POST /dcm4chee-arc/aets/DCM_OTHER/rs/studies/1.3.51.0.1.1.10.24.1.25.1058375.2161499/series/1.2.392.200046.100.14.3449013139376263159036647377795407415000/instances/1.2.392.200046.100.14.66911496743290443206990839777679921242/reject/113039%5EDCM from nu...@127.0.0.1

Archive services normally throw 400 Bad Request if there are invalid characters in the request or if invalid values are sent for certain query parameters.

[LeoGut]

You are right, I am using version:
dcm4che/dcm4chee-arc-psql:5.23.2-secure

I will update the versions and hope it solves the problem. 

[LeoGut]

The problem persists even with the version upgrade.

Does the request 'go outside' the local network?

I am accessing arc-ui on https://my.dns/dcm4chee-arc/ui2.

curl requests from outside the host or from the browser get bad request, using https://my.dns, no port. There is a reverse-proxy in front of arc, keycloak end everything else.

curl request from inside the arc container, using localhost:8443 works

[LeoGut]

I noticed other requests work just fine:  filter, search, count, WADO, and the requests are very similar and use GET.

When I try to reject/delete an instance the requests tries to use POST, and it never shows on arc's log file. It seems to not go through the reverse-proxy (nginx).
I am trying to check if nginx is blocking POST requests somehow.
I also would like to find more details how the rejection services work, could a config parameter on the user-interface fix this? (device-extension / child parameters...)

[Vrinda Nayak]

From archive side, we log every HTTP request received by the archive whether it is GET (filter, search, count, WADO etc) or POST / PUT / DELETE for other services. There is no config parameter to make this work, the archive UI invokes the same request as curl does - and this works, you can test with manual / docker setup of basic unsecured archive and test it (without nginx or any other reverse proxy)

[LeoGut]

Problem solved, it was indeed a problem in my nginx.

http.conf

upstream arc {

                server arc:8443;

}
. . .

location /dcm4chee-arc {

                . . .

                proxy_pass https://arc/̶d̶c̶m̶4̶c̶h̶e̶e̶-̶a̶r̶c̶ ;  <- removed this part

                proxy_pass https://arc;                              <- This is how it looked after fix.

                . . .
}

It was actually a simple mistake but since the other GET requests were working just fine, it didn't really call my attention and I was searching for answers elsewhere.

Thank you for your replies, they helped me to learn how to investigate a little deeper into the system.