IDR / idr-metadata

Curated metadata for all studies published in the Image Data Resource
https://idr.openmicroscopy.org
14 stars 24 forks source link

Errors during NGFF testing on idr-next: 2024-01-16 #685

Closed will-moore closed 4 months ago

will-moore commented 5 months ago

Look for nginx logs...

ssh idr-next.openmicroscopy.org
[wmoore@prod120-proxy nginx]$ ls -alh /var/log/nginx/ | grep "Jan 1"
drwxr-xr-x.  2 root  root 4.0K Jan 17 03:41 .
drwxr-xr-x. 12 root  root 4.0K Jan 14 03:50 ..
-rw-r-----.  1 nginx adm  823K Jan 17 10:26 access.log
-rw-r-----.  1 nginx adm   89K Jan 10 03:06 access.log-20240110.gz
-rw-r-----.  1 nginx adm  159K Jan 11 03:31 access.log-20240111.gz
-rw-r-----.  1 nginx adm   82K Jan 12 03:22 access.log-20240112.gz
-rw-r-----.  1 nginx adm   86K Jan 13 03:42 access.log-20240113.gz
-rw-r-----.  1 nginx adm   86K Jan 14 03:49 access.log-20240114.gz
-rw-r-----.  1 nginx adm   84K Jan 15 03:48 access.log-20240115.gz
-rw-r-----.  1 nginx adm  162K Jan 16 03:45 access.log-20240116.gz
-rw-r-----.  1 nginx adm  8.4M Jan 17 03:40 access.log-20240117
-rw-r-----.  1 nginx adm   12K Jan 17 09:45 error.log
-rw-r-----.  1 nginx adm  1.9K Jan 10 10:31 error.log-20240111.gz
-rw-r-----.  1 nginx adm  2.4K Jan 15 15:00 error.log-20240116.gz
-rw-r-----.  1 nginx adm   37K Jan 16 10:36 error.log-20240117

sudo less error.log-20240117

...
2024/01/16 09:38:50 [warn] 10236#10236: *539804 upstream server temporarily disabled while reading response header from upstream, client: 81.79.160.1, server: prod120-proxy.novalocal, request: "GET /gallery-api/thumbnails/?screen=3302&screen=3301&project=2501&screen=3452&project=2451&screen=3252&screen=3251&screen=3403&screen=3402&screen=3401 HTTP/2.0", subrequest: "/gallery-api/thumbnails/", upstream: "http://192.168.120.174:80/gallery-api/thumbnails/?screen=3302&screen=3301&project=2501&screen=3452&project=2451&screen=3252&screen=3251&screen=3403&screen=3402&screen=3401", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/"
2024/01/16 09:38:50 [error] 10236#10236: *539804 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 81.79.160.1, server: prod120-proxy.novalocal, request: "GET /gallery-api/thumbnails/?screen=3302&screen=3301&project=2501&screen=3452&project=2451&screen=3252&screen=3251&screen=3403&screen=3402&screen=3401 HTTP/2.0", subrequest: "/gallery-api/thumbnails/", upstream: "http://192.168.120.174:80/gallery-api/thumbnails/?screen=3302&screen=3301&project=2501&screen=3452&project=2451&screen=3252&screen=3251&screen=3403&screen=3402&screen=3401", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/"
2024/01/16 09:47:05 [warn] 10238#10238: *542626 an upstream response is buffered to a temporary file /var/cache/nginx/proxy_temp/4/62/0000028624 while reading upstream, client: 134.36.251.166, server: prod120-proxy.novalocal, request: "GET /webgateway/original_file_paths/1921849/?_=1705397880076 HTTP/2.0", upstream: "http://192.168.120.174:80/webgateway/original_file_paths/1921849/?_=1705397880076", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/"
2024/01/16 10:35:03 [warn] 10238#10238: *550125 upstream server temporarily disabled while reading response header from upstream, client: 134.36.251.166, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648047/?callback=jQuery362031136720943034524_1705400862868&_=1705400862932 HTTP/2.0", upstream: "http://192.168.120.174:80/webclient/imgData/10648047/?callback=jQuery362031136720943034524_1705400862868&_=1705400862932", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1"
2024/01/16 10:35:03 [error] 10238#10238: *550125 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 134.36.251.166, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648047/?callback=jQuery362031136720943034524_1705400862868&_=1705400862932 HTTP/2.0", upstream: "http://192.168.120.174:80/webclient/imgData/10648047/?callback=jQuery362031136720943034524_1705400862868&_=1705400862932", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1"
2024/01/16 10:35:05 [warn] 10236#10236: *548482 upstream server temporarily disabled while reading response header from upstream, client: 81.79.160.1, server: prod120-proxy.novalocal, request: "GET /webclient/metadata_preview/image/10648071/?_=1705400875606 HTTP/2.0", subrequest: "/webclient/metadata_preview/image/10648071/", upstream: "http://192.168.120.174:80/webclient/metadata_preview/image/10648071/?_=1705400875606", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/"
2024/01/16 10:35:05 [error] 10236#10236: *548482 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 81.79.160.1, server: prod120-proxy.novalocal, request: "GET /webclient/metadata_preview/image/10648071/?_=1705400875606 HTTP/2.0", subrequest: "/webclient/metadata_preview/image/10648071/", upstream: "http://192.168.120.174:80/webclient/metadata_preview/image/10648071/?_=1705400875606", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/"
2024/01/16 10:35:05 [warn] 10236#10236: *548482 upstream server temporarily disabled while reading response header from upstream, client: 81.79.160.1, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875557&_=1705400875607 HTTP/2.0", upstream: "http://192.168.120.174:80/webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875557&_=1705400875607", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/"
2024/01/16 10:35:05 [error] 10236#10236: *548482 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 81.79.160.1, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875557&_=1705400875607 HTTP/2.0", upstream: "http://192.168.120.174:80/webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875557&_=1705400875607", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/"
2024/01/16 10:35:17 [warn] 10238#10238: *550125 upstream server temporarily disabled while reading response header from upstream, client: 134.36.251.166, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648047/?callback=jQuery362031136720943034524_1705400862871&_=1705400862934 HTTP/2.0", upstream: "http://192.168.120.174:80/webclient/imgData/10648047/?callback=jQuery362031136720943034524_1705400862871&_=1705400862934", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1"
2024/01/16 10:35:17 [error] 10238#10238: *550125 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 134.36.251.166, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648047/?callback=jQuery362031136720943034524_1705400862871&_=1705400862934 HTTP/2.0", upstream: "http://192.168.120.174:80/webclient/imgData/10648047/?callback=jQuery362031136720943034524_1705400862871&_=1705400862934", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1"
2024/01/16 10:35:35 [warn] 10238#10238: *550125 upstream server temporarily disabled while reading response header from upstream, client: 134.36.251.166, server: prod120-proxy.novalocal, request: "GET /webclient/metadata_preview/image/10648048/?_=1705400862935 HTTP/2.0", subrequest: "/webclient/metadata_preview/image/10648048/", upstream: "http://192.168.120.174:80/webclient/metadata_preview/image/10648048/?_=1705400862935", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1"
2024/01/16 10:35:35 [error] 10238#10238: *550125 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 134.36.251.166, server: prod120-proxy.novalocal, request: "GET /webclient/metadata_preview/image/10648048/?_=1705400862935 HTTP/2.0", subrequest: "/webclient/metadata_preview/image/10648048/", upstream: "http://192.168.120.174:80/webclient/metadata_preview/image/10648048/?_=1705400862935", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1"
2024/01/16 10:35:35 [warn] 10238#10238: *550125 upstream server temporarily disabled while reading response header from upstream, client: 134.36.251.166, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648048/?callback=jQuery362031136720943034524_1705400862936&_=1705400862937 HTTP/2.0", upstream: "http://192.168.120.174:80/webclient/imgData/10648048/?callback=jQuery362031136720943034524_1705400862936&_=1705400862937", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1"
2024/01/16 10:35:35 [error] 10238#10238: *550125 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 134.36.251.166, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648048/?callback=jQuery362031136720943034524_1705400862936&_=1705400862937 HTTP/2.0", upstream: "http://192.168.120.174:80/webclient/imgData/10648048/?callback=jQuery362031136720943034524_1705400862936&_=1705400862937", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1"
2024/01/16 10:35:40 [warn] 10236#10236: *548482 upstream server temporarily disabled while reading response header from upstream, client: 81.79.160.1, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875560&_=1705400875609 HTTP/2.0", upstream: "http://192.168.120.174:80/webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875560&_=1705400875609", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/"
2024/01/16 10:35:40 [error] 10236#10236: *548482 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 81.79.160.1, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875560&_=1705400875609 HTTP/2.0", upstream: "http://192.168.120.174:80/webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875560&_=1705400875609", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/"
2024/01/16 10:35:46 [warn] 10238#10238: *550125 upstream server temporarily disabled while reading response header from upstream, client: 134.36.251.166, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648047/?callback=jQuery362031136720943034524_1705400862940&_=1705400862941 HTTP/2.0", upstream: "http://192.168.120.174:80/webclient/imgData/10648047/?callback=jQuery362031136720943034524_1705400862940&_=1705400862941", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1"
2024/01/16 10:35:46 [error] 10238#10238: *550125 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 134.36.251.166, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648047/?callback=jQuery362031136720943034524_1705400862940&_=1705400862941 HTTP/2.0", upstream: "http://192.168.120.174:80/webclient/imgData/10648047/?callback=jQuery362031136720943034524_1705400862940&_=1705400862941", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1"
2024/01/16 10:36:05 [warn] 10236#10236: *548482 upstream server temporarily disabled while reading response header from upstream, client: 81.79.160.1, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875557&_=1705400875607 HTTP/2.0", upstream: "http://192.168.120.132:80/webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875557&_=1705400875607", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/"
2024/01/16 10:36:05 [error] 10236#10236: *548482 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 81.79.160.1, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875557&_=1705400875607 HTTP/2.0", upstream: "http://192.168.120.132:80/webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875557&_=1705400875607", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/"
2024/01/16 10:36:35 [warn] 10238#10238: *550125 upstream server temporarily disabled while reading response header from upstream, client: 134.36.251.166, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648048/?callback=jQuery362031136720943034524_1705400862936&_=1705400862937 HTTP/2.0", upstream: "http://192.168.120.132:80/webclient/imgData/10648048/?callback=jQuery362031136720943034524_1705400862936&_=1705400862937", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1"
2024/01/16 10:36:35 [error] 10238#10238: *550125 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 134.36.251.166, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648048/?callback=jQuery362031136720943034524_1705400862936&_=1705400862937 HTTP/2.0", upstream: "http://192.168.120.132:80/webclient/imgData/10648048/?callback=jQuery362031136720943034524_1705400862936&_=1705400862937", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1"
2024/01/16 10:36:40 [warn] 10236#10236: *548482 upstream server temporarily disabled while reading response header from upstream, client: 81.79.160.1, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875560&_=1705400875609 HTTP/2.0", upstream: "http://192.168.120.132:80/webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875560&_=1705400875609", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/"
2024/01/16 10:36:40 [error] 10236#10236: *548482 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 81.79.160.1, server: prod120-proxy.novalocal, request: "GET /webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875560&_=1705400875609 HTTP/2.0", upstream: "http://192.168.120.132:80/webclient/imgData/10648071/?callback=jQuery36207056919841979_1705400875560&_=1705400875609", host: "idr-next.openmicroscopy.org", referrer: "https://idr-next.openmicroscopy.org/webclient/usertags/"

There's a bunch of gallery-api/thumbnails/ errors to start (around 9:30 ish) then 10:35 - 10:36 there's 6 imgData/ requests for images: - All from idr0091:

sudo less access.log-20240117 gives access logs but no error logging: We were looking at idr0090 around 10:31.. eg:

134.36.66.49 - - [16/Jan/2024:10:31:19 +0000] "GET /webclient/render_thumbnail/12549526/?rdefId=12101094&_=random0.2862405070337033 HTTP/2.0" 200 2834 "https://idr-next.openmicroscopy.org/webclient/?show=well-1011236" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" "-" 0.132 MISS 192.168.120.132:80

Look at times that the main webclient page was requested since we expect to see that at the point that the browser refreshed due to a "logout". See one at 10:26.

[wmoore@prod120-proxy nginx]$ sudo grep " /webclient/?" access.log-20240117
134.36.66.49 - - [16/Jan/2024:09:32:38 +0000] "GET /webclient/?show=project-2801 HTTP/2.0" 200 148282 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/119.0.0.0 Safari/537.36" "-" 0.581 - 192.168.120.132:80
134.36.66.49 - - [16/Jan/2024:09:35:13 +0000] "GET /webclient/?show=image-1230281 HTTP/2.0" 200 148346 "https://idr-next.openmicroscopy.org/iviewer/?well=590733" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/119.0.0.0 Safari/537.36" "-" 0.523 - 192.168.120.132:80
134.36.66.49 - - [16/Jan/2024:09:36:53 +0000] "GET /webclient/?show=well-590776 HTTP/2.0" 200 148346 "https://idr-next.openmicroscopy.org/iviewer/?well=590776" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/119.0.0.0 Safari/537.36" "-" 0.409 - 192.168.120.132:80
134.36.66.49 - - [16/Jan/2024:09:37:14 +0000] "GET /webclient/?show=image-1230542 HTTP/2.0" 200 148346 "https://idr-next.openmicroscopy.org/iviewer/?well=590776" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/119.0.0.0 Safari/537.36" "-" 0.400 - 192.168.120.132:80
134.36.250.254 - - [16/Jan/2024:09:37:54 +0000] "GET /webclient/?show=project-2201 HTTP/2.0" 200 148282 "https://idr-next.openmicroscopy.org/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:121.0) Gecko/20100101 Firefox/121.0" "-" 0.488 - 192.168.120.132:80
81.79.160.1 - - [16/Jan/2024:09:37:56 +0000] "GET /webclient/?show=project-2801 HTTP/2.0" 200 148282 "https://idr-next.openmicroscopy.org/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.6 Safari/605.1.15" "-" 1.864 - 192.168.120.174:80
134.36.251.166 - - [16/Jan/2024:09:37:57 +0000] "GET /webclient/?show=image-1315337 HTTP/2.0" 200 148348 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" "-" 0.963 - 192.168.120.174:80
134.36.66.49 - - [16/Jan/2024:09:42:54 +0000] "GET /webclient/?experimenter=-1 HTTP/2.0" 200 148238 "https://idr-next.openmicroscopy.org/webclient/img_detail/10647647/?dataset=11909" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" "-" 0.262 - 192.168.120.132:80
134.36.250.254 - - [16/Jan/2024:09:52:47 +0000] "GET /webclient/?show=well-1235537 HTTP/2.0" 200 148325 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:121.0) Gecko/20100101 Firefox/121.0" "-" 0.506 - 192.168.120.132:80
81.79.160.1 - - [16/Jan/2024:09:59:56 +0000] "GET /webclient/?show=well-1011236 HTTP/2.0" 200 148325 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.6 Safari/605.1.15" "-" 0.285 - 192.168.120.174:80
134.36.251.166 - - [16/Jan/2024:09:59:56 +0000] "GET /webclient/?show=well-1011236 HTTP/2.0" 200 148325 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" "-" 0.463 - 192.168.120.174:80
134.36.66.49 - - [16/Jan/2024:10:00:16 +0000] "GET /webclient/?show=well-1011236 HTTP/2.0" 200 148309 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" "-" 0.360 - 192.168.120.132:80
81.79.160.1 - - [16/Jan/2024:10:26:55 +0000] "GET /webclient/?show=project-2801 HTTP/2.0" 200 148282 "https://idr-next.openmicroscopy.org/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.6 Safari/605.1.15" "-" 0.390 - 192.168.120.174:80
127.0.0.1 - - [16/Jan/2024:11:00:16 +0000] "GET /webclient/?experimenter=-1 HTTP/1.1" 200 149037 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" "-" 0.276 - 192.168.120.37:80
134.36.250.254 - - [16/Jan/2024:11:36:25 +0000] "GET /webclient/?show=screen-3103 HTTP/2.0" 200 148280 "https://idr-next.openmicroscopy.org/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:121.0) Gecko/20100101 Firefox/121.0" "-" 0.291 - 192.168.120.132:80

I took this screenshot to look for Console errors from Preview panel image viewer 'collapsed' (zero height):

Screenshot 2024-01-16 at 10 44 23

The image 10648048 referred to there is from idr0091 (corresponds to error log above):

[wmoore@prod120-proxy nginx]$ sudo grep "/10648048" access.log-20240117
134.36.251.166 - - [16/Jan/2024:10:34:35 +0000] "GET /webclient/render_thumbnail/10648048/?rdefId=10324053 HTTP/2.0" 200 990 "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" "-" 0.413 STALE -
134.36.251.166 - - [16/Jan/2024:10:36:35 +0000] "GET /webclient/metadata_preview/image/10648048/?_=1705400862935 HTTP/2.0" 200 16399 "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" "-" 120.012 STALE -
134.36.251.166 - - [16/Jan/2024:10:36:35 +0000] "GET /webclient/imgData/10648048/?callback=jQuery362031136720943034524_1705400862936&_=1705400862937 HTTP/2.0" 504 569 "https://idr-next.openmicroscopy.org/webclient/usertags/?experimenter=-1" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" "-" 120.002 - 192.168.120.174:80, 192.168.120.132:80
[wmoore@prod120-omeroreadwrite ~]$ less /opt/omero/server/OMERO.server/var/log/master.err
...
-! 01/06/24 23:23:16.902 OMERO.Glacier2: warning: dispatch exception: ConnectionI.cpp:1573: Ice::MemoryLimitException:
   protocol error: memory limit exceeded:
   requested 1730150430 bytes, maximum allowed is 256000000 bytes (see Ice.MessageSizeMax)
   identity: 42bca4b9-538a-4dfa-96bd-aefacab4dbb8/c15e96ee-ef1a-46c8-b092-525ee48502e5omero.api.RawPixelsStore
   facet: 
   operation: getPlane
   remote host: 127.0.0.1 remote port: 47034
java.io.IOException: '.zarray' expected but is not readable or missing in store.
        at com.bc.zarr.ZarrArray.open(ZarrArray.java:106)
        at com.bc.zarr.ZarrArray.open(ZarrArray.java:99)
        at com.bc.zarr.ZarrArray.open(ZarrArray.java:95)
        at com.bc.zarr.ZarrArray.open(ZarrArray.java:91)
        at loci.formats.services.JZarrServiceImpl.open(JZarrServiceImpl.java:89)
        at loci.formats.in.ZarrReader.openZarr(ZarrReader.java:579)
        at loci.formats.in.ZarrReader.initializeZarrService(ZarrReader.java:467)
        at loci.formats.in.ZarrReader.reopenFile(ZarrReader.java:458)
        at loci.formats.ImageReader.reopenFile(ImageReader.java:869)
        at loci.formats.ReaderWrapper.reopenFile(ReaderWrapper.java:665)
        at loci.formats.ReaderWrapper.reopenFile(ReaderWrapper.java:665)
        at loci.formats.Memoizer.setId(Memoizer.java:712)
        at ome.io.bioformats.BfPixelsWrapper.<init>(BfPixelsWrapper.java:52)
        at ome.io.bioformats.BfPixelBuffer.reader(BfPixelBuffer.java:73)
        at ome.io.bioformats.BfPixelBuffer.setSeries(BfPixelBuffer.java:124)
        at ome.io.nio.PixelsService.createBfPixelBuffer(PixelsService.java:898)
        at ome.io.nio.PixelsService._getPixelBuffer(PixelsService.java:653)
        at ome.io.nio.PixelsService.getPixelBuffer(PixelsService.java:571)
        at ome.services.RenderingBean$12.doWork(RenderingBean.java:2205)
        at jdk.internal.reflect.GeneratedMethodAccessor282.invoke(Unknown Source)

For image 10648048 can see that the Fileset path contains 10648048.zarr, so let's search Blitz logs on all nodes for that yesterday 2024-01-16. Don't see any errors...

[wmoore@prod120-proxy ~]$ cat nodes
omeroreadonly-1
omeroreadonly-2
omeroreadonly-3
omeroreadonly-4
omeroreadwrite

[wmoore@prod120-proxy ~]$ for n in $(cat nodes); do echo $n && ssh $n "grep 418997a378d8 /opt/omero/server/OMERO.server/var/log/Blitz-0.log | grep 2024-01-16"; done
omeroreadonly-1
2024-01-16 10:35:35,553 INFO  [      ome.services.OmeroFilePathResolver] (.Server-25) Metadata only file, resulting path: /data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/.zattrs
2024-01-16 10:35:35,589 INFO  [                loci.formats.ImageReader] (.Server-25) ZarrReader initializing /data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/.zattrs
2024-01-16 10:35:35,811 INFO  [      ome.services.OmeroFilePathResolver] (.Server-11) Metadata only file, resulting path: /data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/.zattrs
2024-01-16 10:35:35,817 INFO  [                loci.formats.ImageReader] (.Server-11) ZarrReader initializing /data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/.zattrs
2024-01-16 11:15:16,448 DEBUG [                   loci.formats.Memoizer] (.Server-25) saved to temp file: /data/OMERO/BioFormatsCache/data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/..zattrs.bfmemo16099173764015296735
2024-01-16 11:15:16,483 DEBUG [                   loci.formats.Memoizer] (.Server-25) saved memo file: /data/OMERO/BioFormatsCache/data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/..zattrs.bfmemo (91345 bytes)
2024-01-16 11:15:16,484 INFO  [                ome.io.nio.PixelsService] (.Server-25) Creating BfPixelBuffer: /data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/.zattrs Series: 0
2024-01-16 11:15:16,537 DEBUG [                   loci.formats.Memoizer] (.Server-11) saved to temp file: /data/OMERO/BioFormatsCache/data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/..zattrs.bfmemo10540699244396677351
2024-01-16 11:15:16,541 DEBUG [                   loci.formats.Memoizer] (.Server-11) saved memo file: /data/OMERO/BioFormatsCache/data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/..zattrs.bfmemo (91345 bytes)
2024-01-16 11:15:16,541 INFO  [                ome.io.nio.PixelsService] (.Server-11) Creating BfPixelBuffer: /data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/.zattrs Series: 0
omeroreadonly-2
omeroreadonly-3
2024-01-16 10:34:35,410 INFO  [      ome.services.OmeroFilePathResolver] (l.Server-5) Metadata only file, resulting path: /data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/.zattrs
2024-01-16 10:34:35,518 INFO  [                loci.formats.ImageReader] (l.Server-5) ZarrReader initializing /data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/.zattrs
2024-01-16 10:34:35,788 INFO  [      ome.services.OmeroFilePathResolver] (l.Server-4) Metadata only file, resulting path: /data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/.zattrs
2024-01-16 10:34:35,794 INFO  [                loci.formats.ImageReader] (l.Server-4) ZarrReader initializing /data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/.zattrs
2024-01-16 11:14:25,171 DEBUG [                   loci.formats.Memoizer] (l.Server-4) saved to temp file: /data/OMERO/BioFormatsCache/data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/..zattrs.bfmemo2437379478352568002
2024-01-16 11:14:25,268 DEBUG [                   loci.formats.Memoizer] (l.Server-4) saved memo file: /data/OMERO/BioFormatsCache/data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/..zattrs.bfmemo (91345 bytes)
2024-01-16 11:14:25,269 INFO  [                ome.io.nio.PixelsService] (l.Server-4) Creating BfPixelBuffer: /data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/.zattrs Series: 0
2024-01-16 11:14:25,564 DEBUG [                   loci.formats.Memoizer] (l.Server-5) saved to temp file: /data/OMERO/BioFormatsCache/data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/..zattrs.bfmemo8461342761922123114
2024-01-16 11:14:25,641 DEBUG [                   loci.formats.Memoizer] (l.Server-5) saved memo file: /data/OMERO/BioFormatsCache/data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/..zattrs.bfmemo (91345 bytes)
2024-01-16 11:14:25,642 INFO  [                ome.io.nio.PixelsService] (l.Server-5) Creating BfPixelBuffer: /data/OMERO/ManagedRepository/demo_2/Blitz-0-Ice.ThreadPool.Server-10/2020-10/02/14-51-51.873_mkngff/4ae7771a-20ab-453a-ba15-418997a378d8.zarr/.zattrs Series: 0
omeroreadonly-4
omeroreadwrite
will-moore commented 5 months ago

Repeated "stress" testing today with similar (worse) outcomes. Requests got slower and eventually the server stopped responding - 504 and 502 Bad Gateway nginx errors due to timeouts.

Starting around 9:53 with https://idr-next.openmicroscopy.org/webclient/img_detail/2855556/

Also 10:02 with https://idr-next.openmicroscopy.org/webclient/?show=well-1230012

Lets check server logs for ERROR today (2024-01-18)...

[wmoore@prod120-proxy ~]$ for n in $(cat nodes); do echo $n && ssh $n "grep ERROR /opt/omero/server/OMERO.server/var/log/Blitz-0.log | grep 2024-01-18" | wc; done
omeroreadonly-1
    597    6863   81099
omeroreadonly-2
      0       0       0
omeroreadonly-3
    289    3363   42428
omeroreadonly-4
      0       0       0
omeroreadwrite
      0       0       0

Errors look similar on both omeroreadonly-1 and omeroreadonly-3 proxy servers...

$ ssh omeroreadonly-1

[wmoore@prod120-omeroreadonly-1 ~]$ grep ERROR /opt/omero/server/OMERO.server/var/log/Blitz-0.log | grep 2024-01-18 | less

2024-01-18 09:51:26,794 ERROR [         ome.services.roi.PopulateRoiJob] (      main) SERVER IMPROPERLY CONFIGURED - CANNOT FIND /opt/omero/server/OMERO.server-5.6.9-ice36/./lib/scripts/omero/import_scripts/Populate_ROI.py
2024-01-18 09:52:13,981 ERROR [        ome.services.util.ServiceHandler] (l.Server-8) Method interface ome.api.IQuery.findAllByQuery invocation took 23067
2024-01-18 09:54:34,104 ERROR [        ome.services.util.ServiceHandler] (l.Server-5) Method interface ome.services.util.Executor$Work.doWork invocation took 130329
2024-01-18 09:54:34,105 ERROR [        ome.services.util.ServiceHandler] (l.Server-5) Method interface omeis.providers.re.RenderingEngine.load invocation took 130350
2024-01-18 10:14:53,957 ERROR [ome.services.db.SelfCorrectingDataSource] (l.Server-2) Failed to acquire connection after retries=3
2024-01-18 10:14:53,958 ERROR [     o.s.blitz.fire.PermissionsVerifierI] (l.Server-2) Exception thrown while checking password for:public
2024-01-18 10:14:58,272 ERROR [ome.services.db.SelfCorrectingDataSource] (.Server-26) Failed to acquire connection after retries=3
2024-01-18 10:14:58,276 ERROR [        ome.services.util.ServiceHandler] (.Server-26) Method interface ome.services.util.Executor$Work.doWork invocation took 95005
2024-01-18 10:14:58,567 ERROR [ome.services.db.SelfCorrectingDataSource] (.Server-28) Failed to acquire connection after retries=3
2024-01-18 10:14:58,569 ERROR [        ome.services.util.ServiceHandler] (.Server-28) Method interface ome.services.util.Executor$Work.doWork invocation took 95004
2024-01-18 10:14:59,643 ERROR [ome.services.db.SelfCorrectingDataSource] (.Server-29) Failed to acquire connection after retries=3
2024-01-18 10:14:59,646 ERROR [        ome.services.util.ServiceHandler] (.Server-29) Method interface ome.services.util.Executor$Work.doWork invocation took 96004
2024-01-18 10:15:07,711 ERROR [ome.services.db.SelfCorrectingDataSource] (.Server-27) Failed to acquire connection after retries=3
2024-01-18 10:15:07,712 ERROR [        ome.services.util.ServiceHandler] (.Server-27) Method interface ome.services.util.Executor$Work.doWork invocation took 96003
2024-01-18 10:15:12,960 ERROR [ome.services.db.SelfCorrectingDataSource] (.Server-32) Failed to acquire connection after retries=3
2024-01-18 10:15:12,961 ERROR [     o.s.blitz.fire.PermissionsVerifierI] (.Server-32) Exception thrown while checking password for:public
2024-01-18 10:15:22,186 ERROR [ome.services.db.SelfCorrectingDataSource] (.Server-30) Failed to acquire connection after retries=3
2024-01-18 10:15:22,187 ERROR [        ome.services.util.ServiceHandler] (.Server-30) Method interface ome.services.util.Executor$Work.doWork invocation took 97003
2024-01-18 10:15:23,425 ERROR [ome.services.db.SelfCorrectingDataSource] (.Server-33) Failed to acquire connection after retries=3
2024-01-18 10:15:23,426 ERROR [        ome.services.util.ServiceHandler] (.Server-33) Method interface ome.services.util.Executor$Work.doWork invocation took 98003
2024-01-18 10:15:23,748 ERROR [ome.services.db.SelfCorrectingDataSource] (.Server-31) Failed to acquire connection after retries=3
$ ssh omeroreadonly-3

[wmoore@prod120-omeroreadonly-3 ~]$ grep ERROR /opt/omero/server/OMERO.server/var/log/Blitz-0.log | grep 2024-01-18 | less

2024-01-18 10:19:29,578 ERROR [ome.services.db.SelfCorrectingDataSource] (3-thread-2) Failed to acquire connection after retries=3
2024-01-18 10:19:29,583 ERROR [        ome.services.util.ServiceHandler] (3-thread-2) Method interface ome.services.util.Executor$Work.doWork invocation took 92009
2024-01-18 10:19:29,588 ERROR [        ome.services.util.ServiceHandler] (.Server-31) Method interface ome.api.IAdmin.getEventContext invocation took 92023
2024-01-18 10:19:29,596 ERROR [        ome.services.util.ServiceHandler] (.Server-25) Method interface ome.services.util.Executor$Work.doWork invocation took 23852
2024-01-18 10:19:29,614 ERROR [        ome.services.util.ServiceHandler] (.Server-24) Method interface ome.api.IConfig.getConfigValues invocation took 79522
2024-01-18 10:19:29,625 ERROR [        ome.services.util.ServiceHandler] (.Server-32) Method interface ome.api.IConfig.getConfigValues invocation took 77266
2024-01-18 10:19:29,631 ERROR [        ome.services.util.ServiceHandler] (.Server-35) Method interface ome.services.util.Executor$Work.doWork invocation took 45500
2024-01-18 10:19:29,644 ERROR [        ome.services.util.ServiceHandler] (2-thread-3) Method interface ome.services.util.Executor$Work.doWork invocation took 74685
2024-01-18 10:20:03,345 ERROR [ome.services.db.SelfCorrectingDataSource] (.Server-22) Failed to acquire connection after retries=3
2024-01-18 10:20:03,345 ERROR [     o.s.blitz.fire.PermissionsVerifierI] (.Server-22) Exception thrown while checking password for:public
2024-01-18 10:20:36,354 ERROR [ome.services.db.SelfCorrectingDataSource] (.Server-27) Failed to acquire connection after retries=3
2024-01-18 10:20:36,354 ERROR [     o.s.blitz.fire.PermissionsVerifierI] (.Server-27) Exception thrown while checking password for:public
2024-01-18 10:21:09,691 ERROR [ome.services.db.SelfCorrectingDataSource] (.Server-34) Failed to acquire connection after retries=3
2024-01-18 10:21:09,693 ERROR [        ome.services.util.ServiceHandler] (.Server-34) Method interface ome.services.util.Executor$Work.doWork invocation took 100003
2024-01-18 10:21:09,696 ERROR [ome.services.db.SelfCorrectingDataSource] (.Server-39) Failed to acquire connection after retries=3
2024-01-18 10:21:09,697 ERROR [        ome.services.util.ServiceHandler] (.Server-39) Method interface ome.services.util.Executor$Work.doWork invocation took 100002

Let's focus on ssh omeroreadonly-1 since the Errors started there earlier and are greater in number... First Error above was at 9:51:26. Checking web logs around then... Doesn't show much...

ssh omeroreadonly-1
[wmoore@prod120-omeroreadonly-1 ~]$ less /opt/omero/web/OMERO.web/var/log/OMEROweb.log 
...
2024-01-18 09:50:11,447  INFO [                           omero.gateway] (proc.23778) connect():2274 created connection (uuid=31be845d-a044-4a79-a099-411bbb998b7b)
2024-01-18 09:50:11,449  INFO [                           omero.gateway] (proc.23253) connect():2274 created connection (uuid=31be845d-a044-4a79-a099-411bbb998b7b)
2024-01-18 09:50:11,499  INFO [                           omero.gateway] (proc.23248) close():1987 closed connection (uuid=31be845d-a044-4a79-a099-411bbb998b7b)
2024-01-18 09:50:11,523  INFO [                           omero.gateway] (proc.23253) connect():2274 created connection (uuid=31be845d-a044-4a79-a099-411bbb998b7b)
2024-01-18 09:50:11,568  INFO [                           omero.gateway] (proc.03357) _register_service():1637 Registered 31be845d-a044-4a79-a099-411bbb998b7b/407663f3-bf39-4267-acb3-c91e08560fdeomero.api.RenderingEngine -t -e 1.1:tcp -h 10.35.199.43 -p 35560 -t 60000:tcp -h 192.1
68.120.132 -p 35560 -t 60000
2024-01-18 09:50:11,575  INFO [                           omero.gateway] (proc.23778) _register_service():1637 Registered 31be845d-a044-4a79-a099-411bbb998b7b/d4077d9c-1b50-4e81-8746-1466c6e32d04omero.api.ThumbnailStore -t -e 1.1:tcp -h 10.35.199.43 -p 35560 -t 60000:tcp -h 192.16
8.120.132 -p 35560 -t 60000
2024-01-18 09:50:11,585  INFO [                           omero.gateway] (proc.23253) _register_service():1637 Registered 31be845d-a044-4a79-a099-411bbb998b7b/efea56e8-d454-45d3-89f3-78e9872c7dbeomero.api.ThumbnailStore -t -e 1.1:tcp -h 10.35.199.43 -p 35560 -t 60000:tcp -h 192.16
8.120.132 -p 35560 -t 60000
2024-01-18 09:50:11,637  INFO [                           omero.gateway] (proc.23253) _unregister_service():1646 Unregistered 31be845d-a044-4a79-a099-411bbb998b7b/efea56e8-d454-45d3-89f3-78e9872c7dbeomero.api.ThumbnailStore -t -e 1.1:tcp -h 10.35.199.43 -p 35560 -t 60000:tcp -h 19
2.168.120.132 -p 35560 -t 60000
2024-01-18 09:50:11,639  INFO [                           omero.gateway] (proc.23778) _unregister_service():1646 Unregistered 31be845d-a044-4a79-a099-411bbb998b7b/d4077d9c-1b50-4e81-8746-1466c6e32d04omero.api.ThumbnailStore -t -e 1.1:tcp -h 10.35.199.43 -p 35560 -t 60000:tcp -h 19
2.168.120.132 -p 35560 -t 60000
2024-01-18 09:50:11,649  INFO [                           omero.gateway] (proc.23253) close():1987 closed connection (uuid=31be845d-a044-4a79-a099-411bbb998b7b)
2024-01-18 09:50:11,649  INFO [                           omero.gateway] (proc.23778) close():1987 closed connection (uuid=31be845d-a044-4a79-a099-411bbb998b7b)
2024-01-18 09:50:11,652  INFO [                           omero.gateway] (proc.23253) close():1987 closed connection (uuid=31be845d-a044-4a79-a099-411bbb998b7b)
2024-01-18 09:50:14,216  INFO [                           omero.gateway] (proc.03357) _unregister_service():1646 Unregistered 31be845d-a044-4a79-a099-411bbb998b7b/407663f3-bf39-4267-acb3-c91e08560fdeomero.api.RenderingEngine -t -e 1.1:tcp -h 10.35.199.43 -p 35560 -t 60000:tcp -h 192.168.120.132 -p 35560 -t 60000
2024-01-18 09:50:14,219  INFO [                           omero.gateway] (proc.03357) close():1987 closed connection (uuid=31be845d-a044-4a79-a099-411bbb998b7b)
2024-01-18 09:50:20,966  INFO [                           omero.gateway] (proc.23253) connect():2274 created connection (uuid=31be845d-a044-4a79-a099-411bbb998b7b)
2024-01-18 09:50:21,277  INFO [                           omero.gateway] (proc.23253) close():1987 closed connection (uuid=31be845d-a044-4a79-a099-411bbb998b7b)
2024-01-18 09:51:27,138 WARNI [                            omero.client] (proc.23790) createSession():633 ApiUsageException:Server not fully initialized - createSession retry: 1
2024-01-18 09:51:27,140 WARNI [                            omero.client] (proc.23789) createSession():633 ApiUsageException:Server not fully initialized - createSession retry: 1
2024-01-18 09:51:27,139 WARNI [                            omero.client] (proc.23778) createSession():633 ApiUsageException:Server not fully initialized - createSession retry: 1
2024-01-18 09:51:27,141 WARNI [                            omero.client] (proc.24450) createSession():633 ApiUsageException:Server not fully initialized - createSession retry: 1
2024-01-18 09:51:28,473  INFO [                           omero.gateway] (proc.24450) connect():2274 created connection (uuid=c3a1d1af-a386-4626-9c59-94723cead69b)
2024-01-18 09:51:28,478  INFO [                           omero.gateway] (proc.23778) connect():2274 created connection (uuid=ab053e43-1690-41fb-b689-2b93709f2894)
2024-01-18 09:51:28,481  INFO [                           omero.gateway] (proc.23789) connect():2274 created connection (uuid=3411287c-af3a-47ac-a194-b8795d6cf621)
2024-01-18 09:51:28,481  INFO [                           omero.gateway] (proc.23790) connect():2274 created connection (uuid=09100273-3a0f-460b-9f15-c49bcec9745c)
2024-01-18 09:51:28,766  INFO [                           omero.gateway] (proc.24450) close():1987 closed connection (uuid=c3a1d1af-a386-4626-9c59-94723cead69b)
2024-01-18 09:51:29,327  INFO [                           omero.gateway] (proc.23789) close():1987 closed connection (uuid=3411287c-af3a-47ac-a194-b8795d6cf621)
2024-01-18 09:51:29,326  INFO [                           omero.gateway] (proc.23790) close():1987 closed connection (uuid=09100273-3a0f-460b-9f15-c49bcec9745c)
2024-01-18 09:51:29,327  INFO [                           omero.gateway] (proc.23778) close():1987 closed connection (uuid=ab053e43-1690-41fb-b689-2b93709f2894)
2024-01-18 09:51:29,895  INFO [                omeroweb.webclient.views] (proc.06744) <module>():138 INIT '6744'
2024-01-18 09:51:32,210  INFO [                                    root] (proc.06744) process_custom_settings():1347 Processing custom settings for module omero_mapr.mapr_settings
2024-01-18 09:51:32,515  INFO [                                    root] (proc.06744) process_custom_settings():1347 Processing custom settings for module omeroweb.api.api_settings
2024-01-18 09:51:32,699  INFO [                                    root] (proc.06744) process_custom_settings():1347 Processing custom settings for module omero_iviewer.iviewer_settings
2024-01-18 09:51:32,784  INFO [                                    root] (proc.06744) process_custom_settings():1347 Processing custom settings for module idr_gallery.gallery_settings
2024-01-18 09:51:33,841  INFO [                           omero.gateway] (proc.06744) connect():2274 created connection (uuid=ab053e43-1690-41fb-b689-2b93709f2894)
...

Looking at web logs on all 5 proxy servers finds a few for yesterday 2024-01-17 (see below) and the day before, but NOTHING for today:

[wmoore@prod120-proxy ~]$ for n in $(cat nodes); do echo $n && ssh $n "grep ERROR /opt/omero/web/OMERO.web/var/log/OMEROweb.log | grep 2024-01-17"; done

omeroreadonly-1
2024-01-17 09:45:17,723 ERROR [                          django.request] (proc.23788) log_response():230 Internal Server Error: /webclient/imgData/2857898/
2024-01-17 09:45:17,723 ERROR [                          django.request] (proc.23788) log_response():230 HTTP 500 <WSGIRequest: GET '/webclient/imgData/2857898/?callback=jQuery36205991047201379455_1705484703723&_=1705484703736'>
omeroreadonly-2
omeroreadonly-3
omeroreadonly-4
omeroreadwrite
2024-01-17 14:22:11,513 ERROR [                          django.request] (proc.26180) log_response():230 Internal Server Error: /webclient/imgData/2857881/
2024-01-17 14:22:11,513 ERROR [                          django.request] (proc.26180) log_response():230 HTTP 500 <WSGIRequest: GET '/webclient/imgData/2857881/?callback=jQuery362035458566226120913_1705500952147&_=1705500952206'>

[wmoore@prod120-proxy ~]$ for n in $(cat nodes); do echo $n && ssh $n "grep ERROR /opt/omero/web/OMERO.web/var/log/OMEROweb.log | grep 2024-01-18"; done
omeroreadonly-1
omeroreadonly-2
omeroreadonly-3
omeroreadonly-4
omeroreadwrite

The JavaScript Error: PanoJS.js:204 Uncaught TypeError: Cannot read properties of null (reading 'offsetWidth') seen when rapidly clicking between thumbnails with the Preview panel open (e.g. here on idr-testing) is from https://github.com/ome/omero-web/blob/9841167a70df2f0174aed2820bcd302873b53df3/omeroweb/webgateway/static/3rdparty/panojs-2.0.0/PanoJS.js#L204 and is due to the imgData JSON response returning after the corresponding viewer HTML has already been replaced. The error is because we are trying to determine the width of the HTML element, but can't because it's no-longer in the page:

Screenshot 2024-01-18 at 11 58 54

will-moore commented 5 months ago

In the browser, loading a plane for idr0011 NGFF images on idr-next.openmicroscopy.org takes 1.2 - 1.3 seconds, whereas for the same Image it takes approx 0.3 seconds on idr.openmicroscopy.org - About 4 times slower for NGFF data on idr-next.

This corresponds to results from testing the performance of idr-next (NGFF data) compared with idr on getPlanes() for idr0011, using check_pixels.py running on idr-next:omeroreadwrite and connecting to idr.openmicroscopy.org,

To get the 3 planes (1 per channel) on idr-next takes 6-9 times longer than it does on IDR:

(venv3) bash-4.2$ python check_pixels.py Plate:5387 --max-planes=sizeC --timing
...
Ratio of local/IDR timing for 3 planes is 6.448353163161899 Image: 2849974
Local took 0:00:01.889864, IDR took 0:00:00.293077
35/48 Check Image:2849975 Plate1-Blue-A [Well F2, Field 1]
Ratio of local/IDR timing for 3 planes is 7.497488775963293 Image: 2849975
Local took 0:00:02.279499, IDR took 0:00:00.304035
36/48 Check Image:2849976 Plate1-Blue-A [Well F3, Field 1]
Ratio of local/IDR timing for 3 planes is 7.483514433936849 Image: 2849976
Local took 0:00:02.166672, IDR took 0:00:00.289526
37/48 Check Image:2849977 Plate1-Blue-A [Well F5, Field 1]
Ratio of local/IDR timing for 3 planes is 7.035636320336583 Image: 2849977
Local took 0:00:02.127098, IDR took 0:00:00.302332
38/48 Check Image:2849978 Plate1-Blue-A [Well E2, Field 1]
Ratio of local/IDR timing for 3 planes is 6.369956084270212 Image: 2849978
Local took 0:00:02.017639, IDR took 0:00:00.316743
39/48 Check Image:2849979 Plate1-Blue-A [Well C8, Field 1]
Ratio of local/IDR timing for 3 planes is 8.606395067899692 Image: 2849979
Local took 0:00:02.582564, IDR took 0:00:00.300075
40/48 Check Image:2849980 Plate1-Blue-A [Well E3, Field 1]
Ratio of local/IDR timing for 3 planes is 8.013746194824963 Image: 2849980
Local took 0:00:02.358734, IDR took 0:00:00.294336
41/48 Check Image:2849981 Plate1-Blue-A [Well D3, Field 1]
Ratio of local/IDR timing for 3 planes is 9.127813243423642 Image: 2849981
Local took 0:00:02.666645, IDR took 0:00:00.292145
42/48 Check Image:2849982 Plate1-Blue-A [Well C6, Field 1]
Ratio of local/IDR timing for 3 planes is 7.333766176970252 Image: 2849982
Local took 0:00:02.180028, IDR took 0:00:00.297259
43/48 Check Image:2849983 Plate1-Blue-A [Well D1, Field 1]
Ratio of local/IDR timing for 3 planes is 5.951195558193271 Image: 2849983
Local took 0:00:01.975422, IDR took 0:00:00.331937
44/48 Check Image:2849984 Plate1-Blue-A [Well A6, Field 1]
Ratio of local/IDR timing for 3 planes is 7.269632766983185 Image: 2849984
Local took 0:00:02.234736, IDR took 0:00:00.307407
45/48 Check Image:2849985 Plate1-Blue-A [Well A2, Field 1]
Ratio of local/IDR timing for 3 planes is 7.3798505495622235 Image: 2849985
Local took 0:00:02.323819, IDR took 0:00:00.314887
46/48 Check Image:2849986 Plate1-Blue-A [Well B4, Field 1]
Ratio of local/IDR timing for 3 planes is 7.5398902465268645 Image: 2849986
Local took 0:00:02.522606, IDR took 0:00:00.334568
47/48 Check Image:2849987 Plate1-Blue-A [Well C4, Field 1]
Ratio of local/IDR timing for 3 planes is 7.71053788410106 Image: 2849987
Local took 0:00:02.297748, IDR took 0:00:00.298001
End: 2024-01-18 13:39:15.190053

For comparison, idr-next is a bit slower than IDR on non NGFF, data, E.g. for idr0002, getPlane() is between 1 and 2 times slower on idr-next than IDR:

(venv3) bash-4.2$ python check_pixels.py Plate:422 --max-planes=sizeC --timing
...
88/96 Check Image:179781 plate1_1_013 [Well 74, Field 1 (Spot 74)]
Ratio of local/IDR timing for 2 planes is 1.5873846630999457 Image: 179781
Local took 0:00:00.941735, IDR took 0:00:00.593262
89/96 Check Image:179782 plate1_1_013 [Well 80, Field 1 (Spot 80)]
Ratio of local/IDR timing for 2 planes is 1.8864566201907107 Image: 179782
Local took 0:00:00.931404, IDR took 0:00:00.493732
90/96 Check Image:179783 plate1_1_013 [Well 48, Field 1 (Spot 48)]
Ratio of local/IDR timing for 2 planes is 1.550902483424802 Image: 179783
Local took 0:00:01.154391, IDR took 0:00:00.744335
91/96 Check Image:179784 plate1_1_013 [Well 16, Field 1 (Spot 16)]
Ratio of local/IDR timing for 2 planes is 1.2027748117081845 Image: 179784
Local took 0:00:00.841436, IDR took 0:00:00.699579
92/96 Check Image:179785 plate1_1_013 [Well 10, Field 1 (Spot 10)]
Ratio of local/IDR timing for 2 planes is 1.5998678177864227 Image: 179785
Local took 0:00:00.808514, IDR took 0:00:00.505363
93/96 Check Image:179786 plate1_1_013 [Well 13, Field 1 (Spot 13)]
Ratio of local/IDR timing for 2 planes is 1.917711069978505 Image: 179786
Local took 0:00:01.284713, IDR took 0:00:00.669920
94/96 Check Image:179787 plate1_1_013 [Well 72, Field 1 (Spot 72)]
Ratio of local/IDR timing for 2 planes is 1.5293623128972729 Image: 179787
Local took 0:00:00.820457, IDR took 0:00:00.536470
95/96 Check Image:179788 plate1_1_013 [Well 86, Field 1 (Spot 86)]
Ratio of local/IDR timing for 2 planes is 1.6206144538739469 Image: 179788
Local took 0:00:00.848638, IDR took 0:00:00.523652
End: 2024-01-18 14:02:31.948497
pwalczysko commented 5 months ago
ssh -A idr-next
ssh omeroreadwrite
ps aux | grep omero
sudo jstack 10023 # of the process omero-s+ 10023 27.5 48.3 39669372 31820924 ?   Sl    2023 16237:03 java -Xmx24G

See also https://openmicroscopy.slack.com/archives/C0K5ME1EW/p1705676461561519 Start challenging the server via web UI. Observe in jstack

...
"Blitz-0-Ice.ThreadPool.Server-185" #121005 prio=5 os_prio=0 cpu=1653080.90ms elapsed=1191511.80s tid=0x00007f996c002800 nid=0xe8e in Object.wait()  [0x00007f98e6bfe000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(java.base@11.0.21/Native Method)
    - waiting on <no object reference available>
    at IceInternal.ThreadPool.followerWait(ThreadPool.java:709)
    - waiting to re-lock in wait() <0x000000020bb0a990> (a IceInternal.ThreadPool)
    at IceInternal.ThreadPool.run(ThreadPool.java:503)
    - waiting to re-lock in wait() <0x000000020bb0a990> (a IceInternal.ThreadPool)
    at IceInternal.ThreadPool.access$300(ThreadPool.java:12)
    at IceInternal.ThreadPool$EventHandlerThread.run(ThreadPool.java:832)
    at java.lang.Thread.run(java.base@11.0.21/Thread.java:829)

"Blitz-0-Ice.ThreadPool.Server-189" #121012 prio=5 os_prio=0 cpu=1650162.26ms elapsed=1191211.80s tid=0x00007f99e0005800 nid=0xf71 in Object.wait()  [0x00007f995f8f9000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(java.base@11.0.21/Native Method)
    - waiting on <no object reference available>
    at IceInternal.ThreadPool.followerWait(ThreadPool.java:709)
    - waiting to re-lock in wait() <0x000000020bb0a990> (a IceInternal.ThreadPool)
    at IceInternal.ThreadPool.run(ThreadPool.java:503)
    - waiting to re-lock in wait() <0x000000020bb0a990> (a IceInternal.ThreadPool)
    at IceInternal.ThreadPool.access$300(ThreadPool.java:12)
    at IceInternal.ThreadPool$EventHandlerThread.run(ThreadPool.java:832)
    at java.lang.Thread.run(java.base@11.0.21/Thread.java:829)

"Blitz-0-Ice.ThreadPool.Server-191" #121014 prio=5 os_prio=0 cpu=1641743.86ms elapsed=1191168.76s tid=0x00007f999419a800 nid=0xf85 in Object.wait()  [0x00007f995edf0000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(java.base@11.0.21/Native Method)
    - waiting on <no object reference available>
    at IceInternal.ThreadPool.followerWait(ThreadPool.java:709)
    - waiting to re-lock in wait() <0x000000020bb0a990> (a IceInternal.ThreadPool)
    at IceInternal.ThreadPool.run(ThreadPool.java:503)
    - waiting to re-lock in wait() <0x000000020bb0a990> (a IceInternal.ThreadPool)
    at IceInternal.ThreadPool.access$300(ThreadPool.java:12)
    at IceInternal.ThreadPool$EventHandlerThread.run(ThreadPool.java:832)
    at java.lang.Thread.run(java.base@11.0.21/Thread.java:829)

"Blitz-0-Ice.ThreadPool.Server-194" #121027 prio=5 os_prio=0 cpu=1671349.90ms elapsed=1190116.41s tid=0x00007f99200c0800 nid=0x1255 in Object.wait()  [0x00007f991b1f0000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(java.base@11.0.21/Native Method)
    - waiting on <no object reference available>
    at IceInternal.ThreadPool.followerWait(ThreadPool.java:709)
    - waiting to re-lock in wait() <0x000000020bb0a990> (a IceInternal.ThreadPool)
    at IceInternal.ThreadPool.run(ThreadPool.java:503)
    - waiting to re-lock in wait() <0x000000020bb0a990> (a IceInternal.ThreadPool)
    at IceInternal.ThreadPool.access$300(ThreadPool.java:12)
    at IceInternal.ThreadPool$EventHandlerThread.run(ThreadPool.java:832)
    at java.lang.Thread.run(java.base@11.0.21/Thread.java:829)

"Blitz-0-Ice.ThreadPool.Server-195" #121028 prio=5 os_prio=0 cpu=1660200.24ms elapsed=1190116.41s tid=0x00007f9a00013800 nid=0x1256 in Object.wait()  [0x00007f991b3f2000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(java.base@11.0.21/Native Method)
    - waiting on <no object reference available>
    at IceInternal.ThreadPool.followerWait(ThreadPool.java:709)
    - waiting to re-lock in wait() <0x000000020bb0a990> (a IceInternal.ThreadPool)
    at IceInternal.ThreadPool.run(ThreadPool.java:503)
    - waiting to re-lock in wait() <0x000000020bb0a990> (a IceInternal.ThreadPool)
    at IceInternal.ThreadPool.access$300(ThreadPool.java:12)
    at IceInternal.ThreadPool$EventHandlerThread.run(ThreadPool.java:832)
    at java.lang.Thread.run(java.base@11.0.21/Thread.java:829)

"Blitz-0-Ice.ThreadPool.Server-199" #121035 prio=5 os_prio=0 cpu=1646402.12ms elapsed=1189638.75s tid=0x00007f9a14004800 nid=0x13a2 in Object.wait()  [0x00007f991befd000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(java.base@11.0.21/Native Method)
    - waiting on <no object reference available>
    at IceInternal.ThreadPool.followerWait(ThreadPool.java:709)
    - waiting to re-lock in wait() <0x000000020bb0a990> (a IceInternal.ThreadPool)
    at IceInternal.ThreadPool.run(ThreadPool.java:503)
    - waiting to re-lock in wait() <0x000000020bb0a990> (a IceInternal.ThreadPool)
    at IceInternal.ThreadPool.access$300(ThreadPool.java:12)
    at IceInternal.ThreadPool$EventHandlerThread.run(ThreadPool.java:832)
    at java.lang.Thread.run(java.base@11.0.21/Thread.java:829)
....
"VM Thread" os_prio=0 cpu=1097118.70ms elapsed=3533128.70s tid=0x00007f9b402ee000 nid=0x272e runnable  

"GC Thread#0" os_prio=0 cpu=974036.94ms elapsed=3533128.72s tid=0x00007f9b40030800 nid=0x2729 runnable  

"GC Thread#1" os_prio=0 cpu=969858.37ms elapsed=3533127.97s tid=0x00007f9ad8001000 nid=0x2747 runnable  

"GC Thread#2" os_prio=0 cpu=972406.00ms elapsed=3533127.97s tid=0x00007f9ad8002800 nid=0x2748 runnable  

"GC Thread#3" os_prio=0 cpu=973408.16ms elapsed=3533127.97s tid=0x00007f9ad8004000 nid=0x2749 runnable  

"GC Thread#4" os_prio=0 cpu=972520.08ms elapsed=3533127.97s tid=0x00007f9ad8005800 nid=0x274a runnable  

"GC Thread#5" os_prio=0 cpu=971685.22ms elapsed=3533127.97s tid=0x00007f9ad8007800 nid=0x274b runnable  

"GC Thread#6" os_prio=0 cpu=969910.72ms elapsed=3533127.97s tid=0x00007f9ad8009000 nid=0x274c runnable  

"GC Thread#7" os_prio=0 cpu=972572.95ms elapsed=3533127.97s tid=0x00007f9ad800a800 nid=0x274d runnable  

"GC Thread#8" os_prio=0 cpu=970457.59ms elapsed=3533127.97s tid=0x00007f9ad800c000 nid=0x274e runnable  

"GC Thread#9" os_prio=0 cpu=971257.80ms elapsed=3533127.97s tid=0x00007f9ad800e000 nid=0x274f runnable  

"GC Thread#10" os_prio=0 cpu=969677.98ms elapsed=3533127.97s tid=0x00007f9ad800f800 nid=0x2750 runnable  

"GC Thread#11" os_prio=0 cpu=971165.01ms elapsed=3533127.97s tid=0x00007f9ad8011000 nid=0x2751 runnable  

"GC Thread#12" os_prio=0 cpu=970578.42ms elapsed=3533127.97s tid=0x00007f9ad8012800 nid=0x2752 runnable  

"G1 Main Marker" os_prio=0 cpu=7639.72ms elapsed=3533128.72s tid=0x00007f9b4008b800 nid=0x272a runnable  

"G1 Conc#0" os_prio=0 cpu=2620279.76ms elapsed=3533128.72s tid=0x00007f9b4008d800 nid=0x272b runnable  

"G1 Conc#1" os_prio=0 cpu=2621736.76ms elapsed=3533126.64s tid=0x00007f9ae4001000 nid=0x278a runnable  

"G1 Conc#2" os_prio=0 cpu=2621023.35ms elapsed=3533126.63s tid=0x00007f9ae4002800 nid=0x278b runnable  

"G1 Refine#0" os_prio=0 cpu=109768.15ms elapsed=3533128.72s tid=0x00007f9b4023b800 nid=0x272c runnable  

"G1 Refine#1" os_prio=0 cpu=36475.89ms elapsed=3533120.06s tid=0x00007f9ae0002000 nid=0x279f runnable  

"G1 Refine#2" os_prio=0 cpu=29140.13ms elapsed=3533120.05s tid=0x00007f99fc001000 nid=0x27a0 runnable  

"G1 Refine#3" os_prio=0 cpu=24832.09ms elapsed=3533120.05s tid=0x00007f99f0001000 nid=0x27a1 runnable  

"G1 Refine#4" os_prio=0 cpu=21612.59ms elapsed=3533120.05s tid=0x00007f99f4001000 nid=0x27a2 runnable  
pwalczysko commented 5 months ago

@joshmoore please see the jstacks in the idr-next:/tmp/jstacks... together with the "narrative" files.

  1. /tmp/jstacks/idr-next-idr0090-first. Pasting the narrative here.
idr-next

12.15 open an OMERO.figure with 1 image
12.16 switch channels on and off
12.17 open an image in iviewer
12.18 in a new tab, hit enter on https://idr-next.openmicroscopy.org/webclient/batch_annotate/?image=12544310&image=12544311&image=12544312&image=12544313&image=12544314&image=12544315&image=12544316&image=12544317&image=12544318&image=12544319&image=12544320&image=12544321&image=12544322&image=12544323&image=12544324&image=12544325&image=12544326&image=12544327&image=12544328&image=12544329&image=12544330&image=12544331&image=12544332&image=12544333&image=12544334&image=12544335&image=12544336&image=12544337&image=12544338&image=12544339&image=12544340&image=12544341&image=12543766&image=12543767&image=12543768&image=12543769&image=12543770&image=12543771&image=12543772&image=12543773&image=12543774&image=12543775&image=12543776&image=12543777&image=12543778&image=12543779&image=12543780&image=12543781&image=12543782&image=12543783&image=12543784&image=12543785&image=12543786&image=12543787&image=12543788&image=12543789&image=12543790&image=12543791&image=12543792&image=12543793&image=12543794&image=12543795&image=12543796&image=12543797&image=12543830&image=12543831&image=12543832&image=12543833&image=12543834&image=12543835&image=12543836&image=12543837&image=12543838&image=12543839&image=12543840&image=12543841&image=12543842&image=12543843&image=12543844&image=12543845&image=12543846&image=12543847&image=12543848&image=12543849&image=12543850&image=12543851&image=12543852&image=12543853&image=12543854&image=12543855&image=12543856&image=12543857&image=12543858&image=12543859&image=12543860&image=12543861&image=12544566&image=12544567&image=12544568&image=12544569&image=12544570&image=12544571&image=12544572&image=12544573&image=12544574&image=12544575&image=12544576&image=12544577&image=12544578&image=12544579&image=12544580&image=12544581&image=12544582&image=12544583&image=12544584&image=12544585&image=12544586&image=12544587&image=12544588&image=12544589&image=12544590&image=12544591&image=12544592&image=12544593&image=12544594&image=12544595&image=12544596&image=12544597&_=1705924416265
12.19 - hit enter on webclient tab - hanging
12.20 - 504 Bad Gateway on webclient
12.21 - refresh webclient - lhp and central p came back
12.22 - open an image in iviewer - iviewer is working
12.25 - stop taking jstacks, iviewer still working (opened a new image)
  1. /tmp/jstacks/idr-next-idr0138. Pasting the narrative
idr-next

12.43 open 1 image in a new figure
12.44 switch channels on and off, add label
12.46 hit enter on https://idr-next.openmicroscopy.org/figure/new/?image=15148898&image=15148899&image=15148900&image=15148901&image=15148902&image=15148903&image=15148904&image=15148905&image=15148906&image=15148907&image=15148908&image=15148909&image=15148910&image=15148911&image=15148912&image=15148913&image=15148914&image=15148915&image=15148916&image=15148917&image=15148918&image=15148919&image=15148920&image=15148921&image=15148922&image=15148923&image=15148924&image=15148925&image=15148926&image=15148927&image=15148928&image=15148929&image=15148930&image=15148931&image=15148932&image=15148933&image=15148934&image=15148935&image=15148936&image=15148937&image=15148938&image=15148939&image=15148940&image=15148941&image=15148942&image=15148943&image=15148944&image=15148945&image=15148946&image=15148947&image=15148948&image=15148949&image=15148950&image=15148951&image=15148952&image=15148953&image=15148954&image=15148955&image=15148956&image=15148957&image=15148958&image=15148959&image=15148960&image=15148961&image=15148962&image=15148963&image=15148964&image=15148965&image=15148966&image=15148967&image=15148968&image=15148969&image=15148970&image=15148971&image=15148972&image=15148973&image=15148974&image=15148975&image=15148976&image=15148977&image=15148978&image=15148979&image=15148980&image=15148981&image=15148982&image=15148983&image=15148984&image=15148985&image=15148986&image=15148987&image=15148988&image=15148989&image=15148990&image=15148991&image=15148992&image=15148993&image=15148994&image=15148995&image=15148996&image=15148997&image=15148998&image=15148999&_=1705926976793
12.47 hit refresh on webclient - it takes a while, but it returns
12.48 switch channels in the large figure on and off and then hit refresh on webclient
12.48 takes quite a while for the webclient to return, but it does
12.49 again, in figure, slide z sliders, make projections, switch channels on and off
12.49 again, hit refresh on webclient
12.50 webclient still not returned
12.51 webclient returned
12.51 again, in figure slide z sliders, make projections, switch channels on and off
12.51 hit refresh on webclient
12.53 webclient still not returned
12.56 webclient returned
  1. /tmp/jstacks/idr-next-idr0002 Pasting the narrative
idr-next

idr0002

13.59 Open an image in figure, switch channels on and off
13.59 open an image in iviewer
14.01 hit enter in new tab on https://idr-next.openmicroscopy.org/figure/new/?image=223928&image=223939&image=224007&image=223999&image=223997&image=224003&image=223971&image=223964&image=224018&image=223987&image=224017&image=223953&image=223988&image=223979&image=223960&image=223994&image=224010&image=223950&image=224016&image=224020&image=223949&image=224015&image=223975&image=224011&image=223958&image=223948&image=223972&image=223992&image=223973&image=223991&image=223978&image=223986&image=223963&image=224002&image=223969&image=223998&image=223941&image=223946&image=223947&image=223954&image=223995&image=224009&image=224004&image=223957&image=223955&image=223933&image=223967&image=224006&image=223989&image=223930&image=224012&image=223942&image=224001&image=223931&image=224019&image=223934&image=223968&image=223938&image=223937&image=224022&image=223940&image=224000&image=223984&image=223996&image=223966&image=223985&image=223945&image=223977&image=223935&image=223951&image=223990&image=223983&image=223936&image=223980&image=224021&image=223974&image=223970&image=223962&image=223965&image=224008&image=223993&image=224013&image=223961&image=223959&image=223981&image=224005&image=223976&image=223956&image=223932&image=223929&image=224023&image=223943&image=224014&image=223944&image=223952&image=223982&image=250083&image=250111&image=250150&image=250088&image=250151&image=250126&image=250093&image=250159&image=250148&image=250095&image=250131&image=250132&image=250162&image=250170&image=250141&image=250114&image=250090&image=250084&image=250164&image=250156&image=250117&image=250172&image=250113&image=250142&image=250128&image=250178&image=250098&image=250137&image=250124&image=250086&image=250147&image=250175&image=250177&image=250161&image=250154&image=250087&image=250096&image=250174&image=250122&image=250169&image=250101&image=250103&image=250112&image=250108&image=250085&image=250094&image=250107&image=250176&image=250118&image=250149&image=250119&image=250157&image=250134&image=250152&image=250155&image=250139&image=250163&image=250144&image=250089&image=250120&image=250135&image=250146&image=250097&image=250091&image=250158&image=250171&image=250100&image=250110&image=250121&image=250106&image=250129&image=250140&image=250123&image=250109&image=250165&image=250104&image=250138&image=250105&image=250160&image=250145&image=250168&image=250099&image=250167&image=250125&image=250092&image=250136&image=250115&image=250127&image=250130&image=250133&image=250143&image=250153&image=250166&image=250102&image=250173&image=250116&_=1705928104541
14.01 refresh webclient
14.01 webclient comes back quickly
14.03 switch channels off on the large figure
14.03 refresh webclient, comes back quickly
14.03 observe that the figure page is not interactive
14.03 observe that Firefox reports on the figure page "this page is slowing down FF"
14.05 the webclient is still refreshing fast
14.11 the figure tab refreshed, and the work in figure with all the images is pretty smooth
14.11 webclient still refreshes quickly
14.12 stopping jstacks
  1. switching to production idr: /tmp/jstacks/idr-idr0002 . Pasting the narrative
IDR prod119

idr

idr0002

14.42 open an image in figure
14.44 open an image in ivewer
14.45 hit enter on new tab on url https://idr.openmicroscopy.org/figure/new/?image=223928&image=223939&image=224007&image=223999&image=223997&image=224003&image=223971&image=223964&image=224018&image=223987&image=224017&image=223953&image=223988&image=223979&image=223960&image=223994&image=224010&image=223950&image=224016&image=224020&image=223949&image=224015&image=223975&image=224011&image=223958&image=223948&image=223972&image=223992&image=223973&image=223991&image=223978&image=223986&image=223963&image=224002&image=223969&image=223998&image=223941&image=223946&image=223947&image=223954&image=223995&image=224009&image=224004&image=223957&image=223955&image=223933&image=223967&image=224006&image=223989&image=223930&image=224012&image=223942&image=224001&image=223931&image=224019&image=223934&image=223968&image=223938&image=223937&image=224022&image=223940&image=224000&image=223984&image=223996&image=223966&image=223985&image=223945&image=223977&image=223935&image=223951&image=223990&image=223983&image=223936&image=223980&image=224021&image=223974&image=223970&image=223962&image=223965&image=224008&image=223993&image=224013&image=223961&image=223959&image=223981&image=224005&image=223976&image=223956&image=223932&image=223929&image=224023&image=223943&image=224014&image=223944&image=223952&image=223982&image=250083&image=250111&image=250150&image=250088&image=250151&image=250126&image=250093&image=250159&image=250148&image=250095&image=250131&image=250132&image=250162&image=250170&image=250141&image=250114&image=250090&image=250084&image=250164&image=250156&image=250117&image=250172&image=250113&image=250142&image=250128&image=250178&image=250098&image=250137&image=250124&image=250086&image=250147&image=250175&image=250177&image=250161&image=250154&image=250087&image=250096&image=250174&image=250122&image=250169&image=250101&image=250103&image=250112&image=250108&image=250085&image=250094&image=250107&image=250176&image=250118&image=250149&image=250119&image=250157&image=250134&image=250152&image=250155&image=250139&image=250163&image=250144&image=250089&image=250120&image=250135&image=250146&image=250097&image=250091&image=250158&image=250171&image=250100&image=250110&image=250121&image=250106&image=250129&image=250140&image=250123&image=250109&image=250165&image=250104&image=250138&image=250105&image=250160&image=250145&image=250168&image=250099&image=250167&image=250125&image=250092&image=250136&image=250115&image=250127&image=250130&image=250133&image=250143&image=250153&image=250166&image=250102&image=250173&image=250116&_=1705928104541
14.46 refresh webclient, comes back immediately
14.47 switch channels on and off on the big figure
14.47 observe that after a short wait <1 minute, figure comes back with expected changes
14.47 switch the channels back on, observe that FF is complaining that the page slows it down (figure tab)
14.48 the figure tab is back, the complaint of FF is gone, the changes on figure are as expected
14.49 one more switch off and on of channels and move the T slider on figure
14.51 again, figure comes back in a minute, after another complaint of FF that it is slowing it down (which goes away with no intervention)
14.52 all the while, the refreshes of webclient are fast, it returns very quickly
pwalczysko commented 5 months ago

geese narratives, Wednesday 24 January 2024

All jstacks in

idr-next:/tmp/jstacks-geese

  1. first repeat with geese on idr0090
    
    geese
    idr-next
    idr0090

10.42 opened an image in figure 10.42 switched channel on and off 10.46 challenge with https://idr-next.openmicroscopy.org/figure/new/?image=12544310&image=12544311&image=12544312&image=12544313&image=12544314&image=12544315&image=12544316&image=12544317&image=12544318&image=12544319&image=12544320&image=12544321&image=12544322&image=12544323&image=12544324&image=12544325&image=12544326&image=12544327&image=12544328&image=12544329&image=12544330&image=12544331&image=12544332&image=12544333&image=12544334&image=12544335&image=12544336&image=12544337&image=12544338&image=12544339&image=12544340&image=12544341&image=12543766&image=12543767&image=12543768&image=12543769&image=12543770&image=12543771&image=12543772&image=12543773&image=12543774&image=12543775&image=12543776&image=12543777&image=12543778&image=12543779&image=12543780&image=12543781&image=12543782&image=12543783&image=12543784&image=12543785&image=12543786&image=12543787&image=12543788&image=12543789&image=12543790&image=12543791&image=12543792&image=12543793&image=12543794&image=12543795&image=12543796&image=12543797&image=12543830&image=12543831&image=12543832&image=12543833&image=12543834&image=12543835&image=12543836&image=12543837&image=12543838&image=12543839&image=12543840&image=12543841&image=12543842&image=12543843&image=12543844&image=12543845&image=12543846&image=12543847&image=12543848&image=12543849&image=12543850&image=12543851&image=12543852&image=12543853&image=12543854&image=12543855&image=12543856&image=12543857&image=12543858&image=12543859&image=12543860&image=12543861&image=12544566&image=12544567&image=12544568&image=12544569&image=12544570&image=12544571&image=12544572&image=12544573&image=12544574&image=12544575&image=12544576&image=12544577&image=12544578&image=12544579&image=12544580&image=12544581&image=12544582&image=12544583&image=12544584&image=12544585&image=12544586&image=12544587&image=12544588&image=12544589&image=12544590&image=12544591&image=12544592&image=12544593&image=12544594&image=12544595&image=12544596&image=12544597&_=1705924416265 10.46 refresh webclient 10.48 webclient still not returned 10.48 Gateway Timeout 504 10.50 webclient still on Gateway Timeout after refresh 10.54 webclient still on Gateway Timeout after refresh 10.55 webclient still on Gateway Timeout after refresh 11.01 explicit manual server restart elicited 11.02 stopped jstack taking


Server restarted 

2. second repeat of geese with idr0090

geese idr-next idr0090 repeat after server restart

11.12 start taking jstacks 11.14 open an image in figure 11.15 switch channels on and off on the figure 11.17 challenge with https://idr-next.openmicroscopy.org/figure/new/?image=12544310&image=12544311&image=12544312&image=12544313&image=12544314&image=12544315&image=12544316&image=12544317&image=12544318&image=12544319&image=12544320&image=12544321&image=12544322&image=12544323&image=12544324&image=12544325&image=12544326&image=12544327&image=12544328&image=12544329&image=12544330&image=12544331&image=12544332&image=12544333&image=12544334&image=12544335&image=12544336&image=12544337&image=12544338&image=12544339&image=12544340&image=12544341&image=12543766&image=12543767&image=12543768&image=12543769&image=12543770&image=12543771&image=12543772&image=12543773&image=12543774&image=12543775&image=12543776&image=12543777&image=12543778&image=12543779&image=12543780&image=12543781&image=12543782&image=12543783&image=12543784&image=12543785&image=12543786&image=12543787&image=12543788&image=12543789&image=12543790&image=12543791&image=12543792&image=12543793&image=12543794&image=12543795&image=12543796&image=12543797&image=12543830&image=12543831&image=12543832&image=12543833&image=12543834&image=12543835&image=12543836&image=12543837&image=12543838&image=12543839&image=12543840&image=12543841&image=12543842&image=12543843&image=12543844&image=12543845&image=12543846&image=12543847&image=12543848&image=12543849&image=12543850&image=12543851&image=12543852&image=12543853&image=12543854&image=12543855&image=12543856&image=12543857&image=12543858&image=12543859&image=12543860&image=12543861&image=12544566&image=12544567&image=12544568&image=12544569&image=12544570&image=12544571&image=12544572&image=12544573&image=12544574&image=12544575&image=12544576&image=12544577&image=12544578&image=12544579&image=12544580&image=12544581&image=12544582&image=12544583&image=12544584&image=12544585&image=12544586&image=12544587&image=12544588&image=12544589&image=12544590&image=12544591&image=12544592&image=12544593&image=12544594&image=12544595&image=12544596&image=12544597&_=1705924416265 11.17 refresh webclient 11.18 webclient returned and thumbs and viewing in Preview works second challenge in a row: 11.19 refresh the figure tab - does not return 11.21 refresh webclient 11.22 Bad Gateway on webclient 11.26 Bad Gateway persists 11.27 explicit manual server restart and stop of jstack taking.


Server restart

3. third repeat of geese on idr0090

geese idr-next idr0090 second repeat after server restart

11.35 start taking jstacks 11.37 open an image in figure 11.37 switch channels on and off on the figure 11.38 challenge with https://idr-next.openmicroscopy.org/figure/new/?image=12544310&image=12544311&image=12544312&image=12544313&image=12544314&image=12544315&image=12544316&image=12544317&image=12544318&image=12544319&image=12544320&image=12544321&image=12544322&image=12544323&image=12544324&image=12544325&image=12544326&image=12544327&image=12544328&image=12544329&image=12544330&image=12544331&image=12544332&image=12544333&image=12544334&image=12544335&image=12544336&image=12544337&image=12544338&image=12544339&image=12544340&image=12544341&image=12543766&image=12543767&image=12543768&image=12543769&image=12543770&image=12543771&image=12543772&image=12543773&image=12543774&image=12543775&image=12543776&image=12543777&image=12543778&image=12543779&image=12543780&image=12543781&image=12543782&image=12543783&image=12543784&image=12543785&image=12543786&image=12543787&image=12543788&image=12543789&image=12543790&image=12543791&image=12543792&image=12543793&image=12543794&image=12543795&image=12543796&image=12543797&image=12543830&image=12543831&image=12543832&image=12543833&image=12543834&image=12543835&image=12543836&image=12543837&image=12543838&image=12543839&image=12543840&image=12543841&image=12543842&image=12543843&image=12543844&image=12543845&image=12543846&image=12543847&image=12543848&image=12543849&image=12543850&image=12543851&image=12543852&image=12543853&image=12543854&image=12543855&image=12543856&image=12543857&image=12543858&image=12543859&image=12543860&image=12543861&image=12544566&image=12544567&image=12544568&image=12544569&image=12544570&image=12544571&image=12544572&image=12544573&image=12544574&image=12544575&image=12544576&image=12544577&image=12544578&image=12544579&image=12544580&image=12544581&image=12544582&image=12544583&image=12544584&image=12544585&image=12544586&image=12544587&image=12544588&image=12544589&image=12544590&image=12544591&image=12544592&image=12544593&image=12544594&image=12544595&image=12544596&image=12544597&_=1705924416265 11.38 refresh webclient 11.39 webclient did not come back 11.40 Bad Gateway on webclient 11.46 Bad Gateway on webclient persists 11.46 explicit manual server restart and stop of jstack taking.

pwalczysko commented 5 months ago

Repeat of goofys (the same day as the geese, Wednesday 24 January 2024)

goofys

Server-restart

idr-next idr0090

jstacks idr-next:/tmp/jstacks-goofys-repeat/idr-next-idr0090-Wed24012024

12.29 start jstacks
12.31 open an image in figure and switch channels on and off
12.32 challenge with https://idr-next.openmicroscopy.org/figure/new/?image=12544310&image=12544311&image=12544312&image=12544313&image=12544314&image=12544315&image=12544316&image=12544317&image=12544318&image=12544319&image=12544320&image=12544321&image=12544322&image=12544323&image=12544324&image=12544325&image=12544326&image=12544327&image=12544328&image=12544329&image=12544330&image=12544331&image=12544332&image=12544333&image=12544334&image=12544335&image=12544336&image=12544337&image=12544338&image=12544339&image=12544340&image=12544341&image=12543766&image=12543767&image=12543768&image=12543769&image=12543770&image=12543771&image=12543772&image=12543773&image=12543774&image=12543775&image=12543776&image=12543777&image=12543778&image=12543779&image=12543780&image=12543781&image=12543782&image=12543783&image=12543784&image=12543785&image=12543786&image=12543787&image=12543788&image=12543789&image=12543790&image=12543791&image=12543792&image=12543793&image=12543794&image=12543795&image=12543796&image=12543797&image=12543830&image=12543831&image=12543832&image=12543833&image=12543834&image=12543835&image=12543836&image=12543837&image=12543838&image=12543839&image=12543840&image=12543841&image=12543842&image=12543843&image=12543844&image=12543845&image=12543846&image=12543847&image=12543848&image=12543849&image=12543850&image=12543851&image=12543852&image=12543853&image=12543854&image=12543855&image=12543856&image=12543857&image=12543858&image=12543859&image=12543860&image=12543861&image=12544566&image=12544567&image=12544568&image=12544569&image=12544570&image=12544571&image=12544572&image=12544573&image=12544574&image=12544575&image=12544576&image=12544577&image=12544578&image=12544579&image=12544580&image=12544581&image=12544582&image=12544583&image=12544584&image=12544585&image=12544586&image=12544587&image=12544588&image=12544589&image=12544590&image=12544591&image=12544592&image=12544593&image=12544594&image=12544595&image=12544596&image=12544597&_=1705924416265
12.32 refresh webclient
12.34 Bad Gateway
12.40 Bad Gateway persists
12.41 restart the server and stop jstacks
pwalczysko commented 5 months ago

Retest of idr0138 on idr-next Wednesday 24 January afternoon

No jstacks taken

14.57 challenge server with https://idr-next.openmicroscopy.org/figure/new/?image=15148898&image=15148899&image=15148900&image=15148901&image=15148902&image=15148903&image=15148904&image=15148905&image=15148906&image=15148907&image=15148908&image=15148909&image=15148910&image=15148911&image=15148912&image=15148913&image=15148914&image=15148915&image=15148916&image=15148917&image=15148918&image=15148919&image=15148920&image=15148921&image=15148922&image=15148923&image=15148924&image=15148925&image=15148926&image=15148927&image=15148928&image=15148929&image=15148930&image=15148931&image=15148932&image=15148933&image=15148934&image=15148935&image=15148936&image=15148937&image=15148938&image=15148939&image=15148940&image=15148941&image=15148942&image=15148943&image=15148944&image=15148945&image=15148946&image=15148947&image=15148948&image=15148949&image=15148950&image=15148951&image=15148952&image=15148953&image=15148954&image=15148955&image=15148956&image=15148957&image=15148958&image=15148959&image=15148960&image=15148961&image=15148962&image=15148963&image=15148964&image=15148965&image=15148966&image=15148967&image=15148968&image=15148969&image=15148970&image=15148971&image=15148972&image=15148973&image=15148974&image=15148975&image=15148976&image=15148977&image=15148978&image=15148979&image=15148980&image=15148981&image=15148982&image=15148983&image=15148984&image=15148985&image=15148986&image=15148987&image=15148988&image=15148989&image=15148990&image=15148991&image=15148992&image=15148993&image=15148994&image=15148995&image=15148996&image=15148997&image=15148998&image=15148999&_=1705926976793
14.57 refresh webclient - returns quickly
14.58 switch channels on and off in figure, refresh webclient
14.58 webclient returns quickly
14.58 open an image in iviewer - goes quickly
16.00 again challenge the server with refreshes of the big figure, changing the channels (on and off on 120 images)
16.01 the refresh of webclient goes fast, there are only small delays on the figure itself
pwalczysko commented 5 months ago

2nd February Friday testing with @joshmoore

Test 1:

jstacks idr-next:/tmp/jstack-nginx-manip/test1-128images-challenge

narrative

10.47 start taking jstacks
10.49 open an image in OMERO.figure
10.50 stop taking jstacks (as Josh instructed, take only when stuck)
10.54 challenge the server with idr0138 and refresh the webclient https://idr-next.openmicroscopy.org/figure/new/?image=12544310&image=12544311&image=12544312&image=12544313&image=12544314&image=12544315&image=12544316&image=12544317&image=12544318&image=12544319&image=12544320&image=12544321&image=12544322&image=12544323&image=12544324&image=12544325&image=12544326&image=12544327&image=12544328&image=12544329&image=12544330&image=12544331&image=12544332&image=12544333&image=12544334&image=12544335&image=12544336&image=12544337&image=12544338&image=12544339&image=12544340&image=12544341&image=12543766&image=12543767&image=12543768&image=12543769&image=12543770&image=12543771&image=12543772&image=12543773&image=12543774&image=12543775&image=12543776&image=12543777&image=12543778&image=12543779&image=12543780&image=12543781&image=12543782&image=12543783&image=12543784&image=12543785&image=12543786&image=12543787&image=12543788&image=12543789&image=12543790&image=12543791&image=12543792&image=12543793&image=12543794&image=12543795&image=12543796&image=12543797&image=12543830&image=12543831&image=12543832&image=12543833&image=12543834&image=12543835&image=12543836&image=12543837&image=12543838&image=12543839&image=12543840&image=12543841&image=12543842&image=12543843&image=12543844&image=12543845&image=12543846&image=12543847&image=12543848&image=12543849&image=12543850&image=12543851&image=12543852&image=12543853&image=12543854&image=12543855&image=12543856&image=12543857&image=12543858&image=12543859&image=12543860&image=12543861&image=12544566&image=12544567&image=12544568&image=12544569&image=12544570&image=12544571&image=12544572&image=12544573&image=12544574&image=12544575&image=12544576&image=12544577&image=12544578&image=12544579&image=12544580&image=12544581&image=12544582&image=12544583&image=12544584&image=12544585&image=12544586&image=12544587&image=12544588&image=12544589&image=12544590&image=12544591&image=12544592&image=12544593&image=12544594&image=12544595&image=12544596&image=12544597&_=1705924416265
10.55 webclient still did not return
10.55 figure is reporting Image not found on the server, or you don't have permission to access it at /figure/imgData/12544574/ in many repetitions
10.56 Bad Gateway 502 
10.56 start taking jstacks again
10.59 Bad Gateway 502 persists
11.00 Bad Gateway persists
11.20 after refresh of browser, webclient is back, but is slow (central pane thumbs load after couple of secs, rhp the same)
11.23 open one image from idr0090 in iviewer
11.24 still did not open in iviewer (the message loading image data in rhp, blank central pane of iviewer)
11.28 iviewer reports "Failed to get image data: 'error'" window
11.28 close the tab with figure where 128 images were opened
11.31 refresh weblicent, observe a new 504 Gateway Timeout
11.32 stop taking jstacks

Test 2 (no jstacks)

12.00 open an image in ivewer idr0090
12.00 observe that the image takes 10 secs to load in iviewer
12.02 open 5 images in OMERO.figure from idr0090 https://idr-next.openmicroscopy.org/figure/new/?image=12542235&image=12542236&image=12542237&image=12542238&image=12542239&_=1706874908207
12.02 refresh the webclient, comes immediately back, clicking around is fast, opens an image in iviewer faster than previously at 12.00 above.
12.05 change the rnd settings on the 5 images in figure. 
12.05 refresh the webclient, comes immediately back, clicking around is fast
12.09 open another image idr0090 in iviewer, takes 5 secs
12.09 refresh weblient, comes back fast, clicking around is fast
12.11 open 10 images in figure https://idr-next.openmicroscopy.org/figure/new/?image=12543478&image=12543479&image=12543480&image=12543481&image=12543482&image=12543483&image=12543484&image=12543485&image=12543486&image=12543487&_=1706875622640
12.13 observe that they render within seconds, refresh webclient
12.13 webclient comes back immediately
12.14 open image in iviewer, takes ca 5 secs
12.16 switch all the channels on on the figure with 10 images
12.16 refresh weblcient comes back immediately, clicking is fast
12.17 open an image in iviewer - takes 3-4 secs
12.18 open 20 images in figure https://idr-next.openmicroscopy.org/figure/new/?image=12543414&image=12543415&image=12543416&image=12543417&image=12543418&image=12543419&image=12543420&image=12543421&image=12543422&image=12543423&image=12543424&image=12543425&image=12543426&image=12543427&image=12543428&image=12543429&image=12543430&image=12543431&image=12543432&image=12543433&_=1706876142137
12.18 refresh webclient, comes back in 2 secs
12.18 images in teh 20 image-figure render in 10 seconds
12.21 open an image in iviewer - takes over a minute to appear
12.24 the iviewer reports "Failed to get image data: 'error'". Close the iviewer tab.
12.24 refresh webclient, comes back fast, browsing is fast
12.26 open an image in iviewer - opens under 10 secs
12.27 trying to open some 15 images in iviewer one after another, always open within 10 secs

Test 3

jstacks idr-next:/tmp/jstack-nginx-manip/test3-gradual-good-then-128-challenge-killedit

13.00 open an image in iviewer - opens in 10 secs
13.02 open 5 images in figure from idr0090 https://idr-next.openmicroscopy.org/figure/new/?image=12542235&image=12542236&image=12542237&image=12542238&image=12542239&_=1706874908207
13.02 refresh webclient, comes back immediately, browsing is fast
13.02 open an image in iviewer, opens in 10 secs
13.05 change the rnd settings on the 5 images in figure. 
13.05 refresh the webclient, comes immediately back, clicking around is fast
13.06  open 10 images in figure https://idr-next.openmicroscopy.org/figure/new/?image=12543478&image=12543479&image=12543480&image=12543481&image=12543482&image=12543483&image=12543484&image=12543485&image=12543486&image=12543487&_=1706875622640
13.07 the images in figure render within seconds
13.07 refresh webclient, comes back immediately, iviewer opens within 10 secs
13.09 open images in ivewer, open within 10 secs
13.11 open 20-image figure https://idr-next.openmicroscopy.org/figure/new/?image=12543414&image=12543415&image=12543416&image=12543417&image=12543418&image=12543419&image=12543420&image=12543421&image=12543422&image=12543423&image=12543424&image=12543425&image=12543426&image=12543427&image=12543428&image=12543429&image=12543430&image=12543431&image=12543432&image=12543433&_=1706876142137
13.11 refresh webclient, comes back in second, open image in iviewer
13.13 switch all channels on the 20-figure on, refresh webclient, comes back in 1 second
13.14 open image in iviewer, opens within 10 secs
13.17 open figure with 40 images https://idr-next.openmicroscopy.org/figure/new/?image=12541718&image=12541719&image=12541720&image=12541721&image=12541722&image=12541723&image=12541724&image=12541725&image=12541726&image=12541727&image=12541728&image=12541729&image=12541730&image=12541731&image=12541732&image=12541733&image=12541734&image=12541735&image=12541736&image=12541737&image=12541738&image=12541739&image=12541740&image=12541741&image=12541742&image=12541743&image=12541744&image=12541745&image=12541746&image=12541747&image=12541748&image=12541749&image=12541430&image=12541431&image=12541432&image=12541433&image=12541434&image=12541435&image=12541436&image=12541437&_=1706879585241
13.18 refresh webclient, comes back immediately but clicking is sluggish
13.20 observe that the figure is reporting that it cannot access images
13.23 figure rendered except 2 images which still have spinner
13.27 switch all channels on the 40 figure on
13.27 refresh webclient, comes immediately back
13.28 open an image in iviewer, done under 5 secs
13.29 - 13.31 keep opening images in iviewer (around 20, sequentially, sec between each image open click)
13.31 observe that all images opened successfully, with varying speeds
13.43 open 80-figure https://idr-next.openmicroscopy.org/figure/new/?image=12550198&image=12550199&image=12550200&image=12550201&image=12550202&image=12550203&image=12550204&image=12550205&image=12550206&image=12550207&image=12550208&image=12550209&image=12550210&image=12550211&image=12550212&image=12550213&image=12550214&image=12550215&image=12550216&image=12550217&image=12550218&image=12550219&image=12550220&image=12550221&image=12550222&image=12550223&image=12550224&image=12550225&image=12550226&image=12550227&image=12550228&image=12550229&image=12550486&image=12550487&image=12550488&image=12550489&image=12550490&image=12550491&image=12550492&image=12550493&image=12550494&image=12550495&image=12550496&image=12550497&image=12550498&image=12550499&image=12550500&image=12550501&image=12550502&image=12550503&image=12550504&image=12550505&image=12550506&image=12550507&image=12550508&image=12550509&image=12550510&image=12550511&image=12550512&image=12550513&image=12550514&image=12550515&image=12550516&image=12550517&image=12550294&image=12550295&image=12550296&image=12550297&image=12550298&image=12550299&image=12550300&image=12550301&image=12550302&image=12550303&image=12550304&image=12550305&image=12550306&image=12550307&image=12550308&image=12550309&_=1706880413270
13.43 refresh webclient, comes back after 5 sec
13.43 clicking in weblient first slow, but picking up speed, once central pane thubms loaded (5 sec), can open images in iviewer in under 10 sec per image
13.56 change the rnd settings on the 80-figure
13.56 refresh webclient, comes back in 5 sec
13.56 start clicking in webclient, Bad Gateway 502
13.56 start taking jstacks
13.57 Bad Gateway went away, weblcient is back, clicking, thumbs in rhp fast, iviewer works
14.11 figure-128 images https://idr-next.openmicroscopy.org/figure/new/?image=12544310&image=12544311&image=12544312&image=12544313&image=12544314&image=12544315&image=12544316&image=12544317&image=12544318&image=12544319&image=12544320&image=12544321&image=12544322&image=12544323&image=12544324&image=12544325&image=12544326&image=12544327&image=12544328&image=12544329&image=12544330&image=12544331&image=12544332&image=12544333&image=12544334&image=12544335&image=12544336&image=12544337&image=12544338&image=12544339&image=12544340&image=12544341&image=12543766&image=12543767&image=12543768&image=12543769&image=12543770&image=12543771&image=12543772&image=12543773&image=12543774&image=12543775&image=12543776&image=12543777&image=12543778&image=12543779&image=12543780&image=12543781&image=12543782&image=12543783&image=12543784&image=12543785&image=12543786&image=12543787&image=12543788&image=12543789&image=12543790&image=12543791&image=12543792&image=12543793&image=12543794&image=12543795&image=12543796&image=12543797&image=12543830&image=12543831&image=12543832&image=12543833&image=12543834&image=12543835&image=12543836&image=12543837&image=12543838&image=12543839&image=12543840&image=12543841&image=12543842&image=12543843&image=12543844&image=12543845&image=12543846&image=12543847&image=12543848&image=12543849&image=12543850&image=12543851&image=12543852&image=12543853&image=12543854&image=12543855&image=12543856&image=12543857&image=12543858&image=12543859&image=12543860&image=12543861&image=12544566&image=12544567&image=12544568&image=12544569&image=12544570&image=12544571&image=12544572&image=12544573&image=12544574&image=12544575&image=12544576&image=12544577&image=12544578&image=12544579&image=12544580&image=12544581&image=12544582&image=12544583&image=12544584&image=12544585&image=12544586&image=12544587&image=12544588&image=12544589&image=12544590&image=12544591&image=12544592&image=12544593&image=12544594&image=12544595&image=12544596&image=12544597&_=1705924416265 - same as in prevous test.
14.12 refresh webclient - Bad Gateway 
14.12 figure is reporting Image not found on the server, or you don't have permission to access it at /figure/imgData/12544574/ in many repetitions
14.15 Bad Gateway persists
14.17 weblient is back, clicking fast, rhp loads slowly
14.18 refresh webclient, Bad Gateway returned
14.21 Bad gateway persists

Test 4

jstacks idr-next:/tmp/jstack-nginx-manip/test4

16.14 open image in iviwere, takes 10 search
16.16 5-image figure https://idr-next.openmicroscopy.org/figure/new/?image=12550557&image=12550558&image=12550559&image=12550560&image=12550561&_=1706890404628
1616 refresh webclient, returns immediately, open an image in iviewer, opens immediately
1617 change rnd settings on 5-figure, refresh webclient, open image iviwer, both immediately oblige
1618 10-images figure https://idr-next.openmicroscopy.org/figure/new/?image=12553399&image=12553400&image=12553401&image=12553402&image=12553403&image=12553404&image=12553405&image=12553406&image=12553407&image=12553408&_=1706890634706 
1618 refresh webclient, open image in iviewer, webclient immediately, iviewer in 10 secs
16.20 change rnd on the 10-figure, refresh webclient - immediately returns, open image in iviewer, opens in 10 secs
16.22 20-images figure https://idr-next.openmicroscopy.org/figure/new/?image=12548663&image=12548664&image=12548665&image=12548666&image=12548667&image=12548668&image=12548669&image=12548670&image=12548671&image=12548672&image=12548673&image=12548674&image=12548675&image=12548676&image=12548677&image=12548678&image=12548679&image=12548680&image=12548681&image=12548682&_=1706890864515
16.22 refresh weblcient, back in 2 secs, open image iviewer, 9 secs
16.24 change rnd in 20-figure, refresh weblicent (immediately), iviewer (10 sec)
16.26 40-image figure https://idr-next.openmicroscopy.org/figure/new/?image=12544886&image=12544887&image=12544888&image=12544889&image=12544890&image=12544891&image=12544892&image=12544893&image=12544894&image=12544895&image=12544896&image=12544897&image=12544898&image=12544899&image=12544900&image=12544901&image=12544902&image=12544903&image=12544904&image=12544905&image=12544906&image=12544907&image=12544908&image=12544909&image=12544910&image=12544911&image=12544912&image=12544913&image=12544914&image=12544915&image=12544916&image=12544917&image=12544918&image=12544919&image=12544920&image=12544921&image=12544922&image=12544923&image=12544924&image=12544925&_=1706891075218
16.26 refresh weblcient, back in 2 secs, open image iviewer, 9 secs
16.27 change rnd on the 40-image figure
16.28 refresh webclient, Bad Gateway 502, 
16.28 webclient back, browsing fast
16.28 open image iviewer, 9 secs
16.30 80-images figure https://idr-next.openmicroscopy.org/figure/new/?image=12548342&image=12548343&image=12548344&image=12548345&image=12548346&image=12548347&image=12548348&image=12548349&image=12548350&image=12548351&image=12548352&image=12548353&image=12548354&image=12548355&image=12548356&image=12548357&image=12548358&image=12548359&image=12548360&image=12548361&image=12548362&image=12548363&image=12548364&image=12548365&image=12548366&image=12548367&image=12548368&image=12548369&image=12548370&image=12548371&image=12548372&image=12548373&image=12548310&image=12548311&image=12548312&image=12548313&image=12548314&image=12548315&image=12548316&image=12548317&image=12548318&image=12548319&image=12548320&image=12548321&image=12548322&image=12548323&image=12548324&image=12548325&image=12548326&image=12548327&image=12548328&image=12548329&image=12548330&image=12548331&image=12548332&image=12548333&image=12548334&image=12548335&image=12548336&image=12548337&image=12548338&image=12548339&image=12548340&image=12548341&image=12548790&image=12548791&image=12548792&image=12548793&image=12548794&image=12548795&image=12548796&image=12548797&image=12548798&image=12548799&image=12548800&image=12548801&image=12548802&image=12548803&image=12548804&image=12548805&_=1706891326510
16.30 refresh webclient, Bad Gateway
16.30 messages in Figure Image not found on the server, or you don't have permission to access it at /figure/imgData/12548340/
16.32 Bad Gateway persists
16.32 webclient returns, clicking fast, iviewer in more thatn ... not coming !
16.34 start taking jstacks
16.36 iviewer (started 16.32 above) reports Failed to get image data: 'error'
16.39 120-images figure https://idr-next.openmicroscopy.org/figure/new/?image=12544310&image=12544311&image=12544312&image=12544313&image=12544314&image=12544315&image=12544316&image=12544317&image=12544318&image=12544319&image=12544320&image=12544321&image=12544322&image=12544323&image=12544324&image=12544325&image=12544326&image=12544327&image=12544328&image=12544329&image=12544330&image=12544331&image=12544332&image=12544333&image=12544334&image=12544335&image=12544336&image=12544337&image=12544338&image=12544339&image=12544340&image=12544341&image=12543766&image=12543767&image=12543768&image=12543769&image=12543770&image=12543771&image=12543772&image=12543773&image=12543774&image=12543775&image=12543776&image=12543777&image=12543778&image=12543779&image=12543780&image=12543781&image=12543782&image=12543783&image=12543784&image=12543785&image=12543786&image=12543787&image=12543788&image=12543789&image=12543790&image=12543791&image=12543792&image=12543793&image=12543794&image=12543795&image=12543796&image=12543797&image=12543830&image=12543831&image=12543832&image=12543833&image=12543834&image=12543835&image=12543836&image=12543837&image=12543838&image=12543839&image=12543840&image=12543841&image=12543842&image=12543843&image=12543844&image=12543845&image=12543846&image=12543847&image=12543848&image=12543849&image=12543850&image=12543851&image=12543852&image=12543853&image=12543854&image=12543855&image=12543856&image=12543857&image=12543858&image=12543859&image=12543860&image=12543861&image=12544566&image=12544567&image=12544568&image=12544569&image=12544570&image=12544571&image=12544572&image=12544573&image=12544574&image=12544575&image=12544576&image=12544577&image=12544578&image=12544579&image=12544580&image=12544581&image=12544582&image=12544583&image=12544584&image=12544585&image=12544586&image=12544587&image=12544588&image=12544589&image=12544590&image=12544591&image=12544592&image=12544593&image=12544594&image=12544595&image=12544596&image=12544597&_=1705924416265 
16.40 refresh webclient - Bad Gateway
16.42 Bad GAteway persists