Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Podman doesn't respond (hangs on "DoRequest Method: GET URI: http://d/v4.5.1/libpod/_ping") #19113

Closed
informeti opened this issue Jul 4, 2023 · 10 comments
Closed

Podman doesn't respond (hangs on "DoRequest Method: GET URI: http://d/v4.5.1/libpod/_ping") #19113

informeti opened this issue Jul 4, 2023 · 10 comments
Labels
kind/bug Categorizes issue or PR as related to a bug. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. machine windows issue/bug on Windows

Comments

@informeti
Copy link

Bug description

Every now and then, during seemingly normal usage of Podman, the Podman CLI / Podman Desktop / docker-compose will become unresponsive.

I couldn't find any particular trigger. It also occurs with colleagues who installed Podman using the installer.

Once unresponsive, logging of various commands looks like this:

$ podman --log-level=debug info
time="2023-07-04T10:46:46+02:00" level=info msg="C:\\Users\\user\\scoop\\apps\\podman\\current\\podman.exe filtering at log level debug"
time="2023-07-04T10:46:46+02:00" level=debug msg="Called info.PersistentPreRunE(C:\\Users\\user\\scoop\\apps\\podman\\current\\podman.exe --log-level=debug info)"
time="2023-07-04T10:46:46+02:00" level=debug msg="SSH Ident Key \"C:\\\\Users\\\\user\\\\.ssh\\\\podman-machine-default\" SHA256:jojbOFmMd6D1/Numph4R4y+wW/9h5dvfeot8iVb0xQA ssh-ed25519"
time="2023-07-04T10:46:46+02:00" level=debug msg="DoRequest Method: GET URI: http://d/v4.5.1/libpod/_ping"

It seems like the issue exists between Windows and the WSL machine. If I manually enter the WSL machine, I can still interact with podman:

$ wsl -d podman-machine-default
$ exit
$ sudo podman --log-level=debug info
INFO[0000] podman filtering at log level debug
DEBU[0000] Called info.PersistentPreRunE(podman --log-level=debug info)
DEBU[0000] Using conmon: "/usr/bin/conmon"
DEBU[0000] Initializing boltdb state at /var/lib/containers/storage/libpod/bolt_state.db
DEBU[0000] Using graph driver overlay
DEBU[0000] Using graph root /var/lib/containers/storage
DEBU[0000] Using run root /run/containers/storage
DEBU[0000] Using static dir /var/lib/containers/storage/libpod
DEBU[0000] Using tmp dir /run/libpod
DEBU[0000] Using volume path /var/lib/containers/storage/volumes
DEBU[0000] Using transient store: false
DEBU[0000] [graphdriver] trying provided driver "overlay"
DEBU[0000] Cached value indicated that overlay is supported
DEBU[0000] Cached value indicated that overlay is supported
DEBU[0000] Cached value indicated that metacopy is being used
DEBU[0000] Cached value indicated that native-diff is not being used
INFO[0000] Not using native diff for overlay, this may cause degraded performance for building images: kernel has CONFIG_OVERLAY_FS_REDIRECT_DIR enabled
DEBU[0000] backingFs=extfs, projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=true
DEBU[0000] Initializing event backend file
DEBU[0000] Configured OCI runtime ocijail initialization failed: no valid executable found for OCI runtime ocijail: invalid argument
DEBU[0000] Configured OCI runtime runc initialization failed: no valid executable found for OCI runtime runc: invalid argument
DEBU[0000] Configured OCI runtime krun initialization failed: no valid executable found for OCI runtime krun: invalid argument
DEBU[0000] Configured OCI runtime runsc initialization failed: no valid executable found for OCI runtime runsc: invalid argument
DEBU[0000] Configured OCI runtime youki initialization failed: no valid executable found for OCI runtime youki: invalid argument
DEBU[0000] Configured OCI runtime crun-wasm initialization failed: no valid executable found for OCI runtime crun-wasm: invalid argument
DEBU[0000] Configured OCI runtime runj initialization failed: no valid executable found for OCI runtime runj: invalid argument
DEBU[0000] Configured OCI runtime kata initialization failed: no valid executable found for OCI runtime kata: invalid argument
DEBU[0000] Using OCI runtime "/usr/bin/crun"
INFO[0000] Setting parallel job count to 37
DEBU[0000] Loading registries configuration "/etc/containers/registries.conf"
DEBU[0000] Loading registries configuration "/etc/containers/registries.conf.d/000-shortnames.conf"
DEBU[0000] Loading registries configuration "/etc/containers/registries.conf.d/999-podman-machine.conf"
host:
  arch: amd64
  buildahVersion: 1.30.0
  cgroupControllers:
  - cpuset
  - cpu
  - cpuacct
  - blkio
  - memory
  - devices
  - freezer
  - net_cls
  - perf_event
  - net_prio
  - hugetlb
  - pids
  - rdma
  - misc
  cgroupManager: cgroupfs
  cgroupVersion: v1
  conmon:
    package: conmon-2.1.7-2.fc37.x86_64
    path: /usr/bin/conmon
    version: 'conmon version 2.1.7, commit: '
  cpuUtilization:
    idlePercent: 99.49
    systemPercent: 0.24
    userPercent: 0.27
  cpus: 12
  databaseBackend: boltdb
  distribution:
    distribution: fedora
    variant: container
    version: "37"
  eventLogger: file
  hostname: myhost
  idMappings:
    gidmap: null
    uidmap: null
  kernel: 5.15.90.1-microsoft-standard-WSL2
  linkmode: dynamic
  logDriver: k8s-file
  memFree: 10758873088
  memTotal: 16656736256
  networkBackend: netavark
  ociRuntime:
    name: crun
    package: crun-1.8.5-1.fc37.x86_64
    path: /usr/bin/crun
    version: |-
      crun version 1.8.5
      commit: b6f80f766c9a89eb7b1440c0a70ab287434b17ed
      rundir: /run/crun
      spec: 1.0.0
      +SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +CRIU +LIBKRUN +WASM:wasmedge +YAJL
  os: linux
  remoteSocket:
    exists: true
    path: /run/podman/podman.sock
  security:
    apparmorEnabled: false
    capabilities: CAP_CHOWN,CAP_DAC_OVERRIDE,CAP_FOWNER,CAP_FSETID,CAP_KILL,CAP_NET_BIND_SERVICE,CAP_SETFCAP,CAP_SETGID,CAP_SETPCAP,CAP_SETUID,CAP_SYS_CHROOT
    rootless: false
    seccompEnabled: true
    seccompProfilePath: /usr/share/containers/seccomp.json
    selinuxEnabled: false
  serviceIsRemote: false
  slirp4netns:
    executable: /usr/bin/slirp4netns
    package: slirp4netns-1.2.0-8.fc37.x86_64
    version: |-
      slirp4netns version 1.2.0
      commit: 656041d45cfca7a4176f6b7eed9e4fe6c11e8383
      libslirp: 4.7.0
      SLIRP_CONFIG_VERSION_MAX: 4
      libseccomp: 2.5.3
  swapFree: 4294967296
  swapTotal: 4294967296
  uptime: 0h 55m 2.00s
plugins:
  authorization: null
  log:
  - k8s-file
  - none
  - passthrough
  - journald
  network:
  - bridge
  - macvlan
  - ipvlan
  volume:
  - local
registries:
  search:
  - docker.io
store:
  configFile: /usr/share/containers/storage.conf
  containerStore:
    number: 0
    paused: 0
    running: 0
    stopped: 0
  graphDriverName: overlay
  graphOptions:
    overlay.mountopt: nodev,metacopy=on
  graphRoot: /var/lib/containers/storage
  graphRootAllocated: 1081101176832
  graphRootUsed: 9775996928
  graphStatus:
    Backing Filesystem: extfs
    Native Overlay Diff: "false"
    Supports d_type: "true"
    Using metacopy: "true"
  imageCopyTmpDir: /var/tmp
  imageStore:
    number: 0
  runRoot: /run/containers/storage
  transientStore: false
  volumePath: /var/lib/containers/storage/volumes
version:
  APIVersion: 4.5.0
  Built: 1681486976
  BuiltTime: Fri Apr 14 17:42:56 2023
  GitCommit: ""
  GoVersion: go1.19.7
  Os: linux
  OsArch: linux/amd64
  Version: 4.5.0

DEBU[0000] Called info.PersistentPostRunE(podman --log-level=debug info)
DEBU[0000] Shutting down engines

The podman socket seems to be running correctly:

$ systemctl status podman.socket
● podman.socket - Podman API Socket
     Loaded: loaded (/usr/lib/systemd/system/podman.socket; enabled; preset: disabled)
     Active: active (listening) since Tue 2023-07-04 10:01:37 CEST; 56min ago
   Triggers: ● podman.service
       Docs: man:podman-system-service(1)
     Listen: /run/podman/podman.sock (Stream)
     CGroup: /system.slice/podman.socket

Jul 04 10:01:37 myhost systemd[1]: Listening on podman.socket - Podman API Socket.

Back on the host side, where Podman is still unresponsive, I can still inspect the machine:

$ podman machine inspect
[
     {
          "ConfigPath": {
               "Path": "C:\\Users\\user\\.config\\containers\\podman\\machine\\wsl\\podman-machine-default.json"
          },
          "ConnectionInfo": {
               "PodmanSocket": null,
               "PodmanPipe": {
                    "Path": "\\\\.\\pipe\\podman-machine-default"
               }
          },
          "Created": "2023-06-16T11:21:21.2761023+02:00",
          "Image": {
               "IgnitionFilePath": {
                    "Path": ""
               },
               "ImageStream": "35",
               "ImagePath": {
                    "Path": "C:\\Users\\user\\.local\\share\\containers\\podman\\machine\\wsl\\podman-machine-default_fedora-podman-amd64-v37.0.38.tar"
               }
          },
          "LastUp": "2023-07-04T10:47:09.0779674+02:00",
          "Name": "podman-machine-default",
          "Resources": {
               "CPUs": 12,
               "DiskSize": 12629049344,
               "Memory": 2809405440
          },
          "SSHConfig": {
               "IdentityPath": "C:\\Users\\user\\.ssh\\podman-machine-default",
               "Port": 60931,
               "RemoteUsername": "user"
          },
          "State": "running"
     }
]

Workaround

If I close Podman Desktop, perform wsl --shutdown, and start Podman Desktop again (which automatically starts the WSL machine), the issue is gone for the moment being.

Operating system

Windows 10

Installation Method

Scoop (Windows)

Version

1.1.0

Steps to reproduce

No response

Relevant log output

No response

Additional context

No response
@benoitf benoitf transferred this issue from podman-desktop/podman-desktop Jul 4, 2023
@benoitf
Copy link
Contributor

benoitf commented Jul 4, 2023

thanks for the report @informeti
I'm transferring the issue to podman repository as WSL machine is managed by this project.

@Luap99
Copy link
Member

Luap99 commented Jul 4, 2023

Does the command which hangs timeout eventually or just hang forever?

Is the podman system service process running, there was a bug with the systemd socket activation recently: #18862

Inside the VM can you provide the service logs with journalctl -u podman.service.

@Luap99 Luap99 added kind/bug Categorizes issue or PR as related to a bug. machine windows issue/bug on Windows labels Jul 4, 2023
@informeti
Copy link
Author

Does the command which hangs timeout eventually or just hang forever?

It seems to hang forever. In the case of this report, I waited for about 45 minutes before aborting it.

Is the podman system service process running, there was a bug with the systemd socket activation recently: #18862

I'm not sure what to look for. In the WSL machine, the podman.service systemd service never seems to be running, even when this issue is not occurring:

$ systemctl status podman
○ podman.service - Podman API Service
     Loaded: loaded (/usr/lib/systemd/system/podman.service; disabled; preset: disabled)
     Active: inactive (dead)
TriggeredBy: ● podman.socket
       Docs: man:podman-system-service(1)

Inside the VM can you provide the service logs with journalctl -u podman.service.

It seems like this log doesn't contain anything:

$ journalctl -u podman.service
-- No entries --

Then again, right now the issue isn't occurring (I really cant tell what's triggering it, and the frequency varies from multiple times a day to days without issue). Not sure if I'd see any log entries while Podman isn't responding.

@Luap99
Copy link
Member

Luap99 commented Jul 4, 2023

Do you use the default machine setting, i.e. not --rootful ? It is running as rootless user by default so you need to switch to the user user.
Then you can check logs journalctl --user -u podman.service

@informeti
Copy link
Author

Ahh, while I'm not sure I understood it correctly, I found logs now.

I enter the machine using wsl -d podman-machine-default, and I always see a message saying I need to exit to access the parent namespace, and usually I exit to the parent namespace:

$ wsl -d podman-machine-default

You will be automatically entered into a nested process namespace where
systemd is running. If you need to access the parent namespace, hit ctrl-d
or type exit. This also means to log out you need to exit twice.

But now I did remain in the "nested process namespace", and here, I do get a lot of logs (although the service is still marked as inactive and disabled):

Here's the relevant part of the log, i.e. starting a bit before the issue occurred, until the point where I "rebooted" the WSL machine with wsl --shutdown.

Jul 03 16:16:52 myhost podman[78]: @ - - [03/Jul/2023:16:16:52 +0200] "GET /libpod/_ping HTTP/1.1" 200 2 "" ""
Jul 03 16:16:55 myhost podman[78]: @ - - [03/Jul/2023:08:52:53 +0200] "GET /events HTTP/1.1" 200 84472 "" ""
-- Boot 99e077224caa4b29bfa7d6322f4c2a38 --
Jul 04 10:01:38 myhost systemd[44]: Starting podman.service - Podman API Service...
Jul 04 10:01:38 myhost systemd[44]: Started podman.service - Podman API Service.
Jul 04 10:01:39 myhost podman[79]: 2023-07-04 10:01:39.1995571 +0200 CEST m=+0.087898801 system refresh
Jul 04 10:10:07 myhost podman[79]: 2023-07-04 10:10:07.514222611 +0200 CEST m=+508.402564312 container create c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=5b3b0ac931e7_web-db, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.version=2.19.0, com.microsoft.product=Microsoft SQL Server, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.replace=5b3b0ac931e7630c68f3d56b1537ed666953f740fba9b254cb120e8af11c1f3a, com.docker.compose.project=web, com.microsoft.version=15.0.4188.2, com.docker.compose.depends_on=, com.docker.compose.service=db, com.docker.compose.oneoff=False, com.docker.compose.config-hash=8da245649ffdbf263ed06372c4b5116d3e85be5df5aa8fbf1883bf585e0da71d, com.docker.compose.container-number=1, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, vendor=Microsoft)
Jul 04 10:10:07 myhost podman[79]: 2023-07-04 10:10:07.706239662 +0200 CEST m=+508.594581463 container remove 5b3b0ac931e7630c68f3d56b1537ed666953f740fba9b254cb120e8af11c1f3a (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, vendor=Microsoft, com.docker.compose.container-number=1, com.docker.compose.oneoff=False, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.project=web, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.service=db, com.microsoft.version=15.0.4188.2, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.config-hash=9b2743b9772864af5e6c43ea7cd1be49048923bb5ddecdd3a08d44887cd4967b, com.docker.compose.version=2.19.0, com.microsoft.product=Microsoft SQL Server, com.docker.compose.depends_on=)
Jul 04 10:10:07 myhost podman[79]: 2023-07-04 10:10:07.71641147 +0200 CEST m=+508.604753171 container rename c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.docker.compose.version=2.19.0, com.docker.compose.oneoff=False, com.docker.compose.replace=5b3b0ac931e7630c68f3d56b1537ed666953f740fba9b254cb120e8af11c1f3a, com.microsoft.product=Microsoft SQL Server, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.service=db, com.docker.compose.config-hash=8da245649ffdbf263ed06372c4b5116d3e85be5df5aa8fbf1883bf585e0da71d, com.docker.compose.project=web, vendor=Microsoft, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.container-number=1, com.microsoft.version=15.0.4188.2, com.docker.compose.depends_on=)
Jul 04 10:10:08 myhost podman[79]: 2023-07-04 10:10:08.072889253 +0200 CEST m=+508.961231054 container init c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.microsoft.version=15.0.4188.2, com.docker.compose.config-hash=8da245649ffdbf263ed06372c4b5116d3e85be5df5aa8fbf1883bf585e0da71d, com.docker.compose.replace=5b3b0ac931e7630c68f3d56b1537ed666953f740fba9b254cb120e8af11c1f3a, com.microsoft.product=Microsoft SQL Server, com.docker.compose.depends_on=, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, vendor=Microsoft, com.docker.compose.project=web, com.docker.compose.oneoff=False, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.version=2.19.0, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.container-number=1, com.docker.compose.service=db)
Jul 04 10:10:08 myhost podman[79]: 2023-07-04 10:10:08.076182656 +0200 CEST m=+508.964524357 container attach c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.docker.compose.depends_on=, com.docker.compose.service=db, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.project=web, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.microsoft.product=Microsoft SQL Server, com.docker.compose.oneoff=False, com.docker.compose.config-hash=8da245649ffdbf263ed06372c4b5116d3e85be5df5aa8fbf1883bf585e0da71d, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.microsoft.version=15.0.4188.2, com.docker.compose.version=2.19.0, vendor=Microsoft, com.docker.compose.container-number=1, com.docker.compose.replace=5b3b0ac931e7630c68f3d56b1537ed666953f740fba9b254cb120e8af11c1f3a)
Jul 04 10:10:08 myhost podman[79]: 2023-07-04 10:10:08.138168712 +0200 CEST m=+509.026510413 container start c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.docker.compose.service=db, com.docker.compose.depends_on=, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.version=2.19.0, vendor=Microsoft, com.docker.compose.config-hash=8da245649ffdbf263ed06372c4b5116d3e85be5df5aa8fbf1883bf585e0da71d, com.docker.compose.project=web, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.replace=5b3b0ac931e7630c68f3d56b1537ed666953f740fba9b254cb120e8af11c1f3a, com.microsoft.product=Microsoft SQL Server, com.docker.compose.oneoff=False, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.container-number=1, com.microsoft.version=15.0.4188.2)
Jul 04 10:10:08 myhost web-db[181]: SQL Server 2019 will run as non-root by default.
Jul 04 10:10:08 myhost web-db[181]: This container is running as user mssql.
Jul 04 10:10:08 myhost web-db[181]: Your master database file is owned by mssql.
Jul 04 10:10:08 myhost web-db[181]: To learn more visit https://go.microsoft.com/fwlink/?linkid=2099216.
Jul 04 10:10:08 myhost web-db[181]: Starting database instance
Jul 04 10:10:43 myhost podman[79]: 2023-07-04 10:10:43.698268027 +0200 CEST m=+544.586609728 container died c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.microsoft.version=15.0.4188.2, com.docker.compose.replace=5b3b0ac931e7630c68f3d56b1537ed666953f740fba9b254cb120e8af11c1f3a, com.microsoft.product=Microsoft SQL Server, com.docker.compose.oneoff=False, com.docker.compose.service=db, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.project=web, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.version=2.19.0, com.docker.compose.config-hash=8da245649ffdbf263ed06372c4b5116d3e85be5df5aa8fbf1883bf585e0da71d, com.docker.compose.depends_on=, vendor=Microsoft, com.docker.compose.container-number=1)
Jul 04 10:10:44 myhost podman[79]: 2023-07-04 10:10:44.108374946 +0200 CEST m=+544.996716647 container cleanup c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.depends_on=, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.config-hash=8da245649ffdbf263ed06372c4b5116d3e85be5df5aa8fbf1883bf585e0da71d, com.docker.compose.project=web, com.microsoft.product=Microsoft SQL Server, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.version=2.19.0, com.docker.compose.container-number=1, com.docker.compose.oneoff=False, com.docker.compose.service=db, com.docker.compose.replace=5b3b0ac931e7630c68f3d56b1537ed666953f740fba9b254cb120e8af11c1f3a, vendor=Microsoft, com.microsoft.version=15.0.4188.2)
Jul 04 10:10:44 myhost podman[426]: 2023-07-04 10:10:44.109438847 +0200 CEST m=+0.413350524 container cleanup c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.docker.compose.service=db, com.docker.compose.version=2.19.0, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.oneoff=False, com.docker.compose.project=web, com.microsoft.product=Microsoft SQL Server, vendor=Microsoft, com.docker.compose.config-hash=8da245649ffdbf263ed06372c4b5116d3e85be5df5aa8fbf1883bf585e0da71d, com.microsoft.version=15.0.4188.2, com.docker.compose.depends_on=, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.container-number=1, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.replace=5b3b0ac931e7630c68f3d56b1537ed666953f740fba9b254cb120e8af11c1f3a)
Jul 04 10:11:08 myhost podman[79]: 2023-07-04 10:11:08.469061692 +0200 CEST m=+569.357403393 container create 8b89601e5e39200b1d3849be8ca1d832bd0574a51638e40ac33a6c3071b68370 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=c06cabe4fa8b_web-db, com.microsoft.product=Microsoft SQL Server, com.docker.compose.depends_on=, com.docker.compose.project=web, vendor=Microsoft, com.docker.compose.version=2.19.0, com.docker.compose.oneoff=False, com.docker.compose.config-hash=fcde2100d6bb806bc59123f6feeb6c6ea90717c59fcf214ccb7bddba9877b86a, com.docker.compose.service=db, com.microsoft.version=15.0.4188.2, com.docker.compose.replace=c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f, com.docker.compose.container-number=1, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml)
Jul 04 10:11:08 myhost podman[79]: 2023-07-04 10:11:08.736999163 +0200 CEST m=+569.625340864 container remove c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.microsoft.version=15.0.4188.2, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.depends_on=, com.microsoft.product=Microsoft SQL Server, vendor=Microsoft, com.docker.compose.container-number=1, com.docker.compose.version=2.19.0, com.docker.compose.config-hash=8da245649ffdbf263ed06372c4b5116d3e85be5df5aa8fbf1883bf585e0da71d, com.docker.compose.replace=5b3b0ac931e7630c68f3d56b1537ed666953f740fba9b254cb120e8af11c1f3a, com.docker.compose.project=web, com.docker.compose.service=db, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.oneoff=False, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml)
Jul 04 10:11:08 myhost podman[79]: 2023-07-04 10:11:08.752536879 +0200 CEST m=+569.640878580 container rename 8b89601e5e39200b1d3849be8ca1d832bd0574a51638e40ac33a6c3071b68370 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, vendor=Microsoft, com.docker.compose.container-number=1, com.microsoft.product=Microsoft SQL Server, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.oneoff=False, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.replace=c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f, com.docker.compose.config-hash=fcde2100d6bb806bc59123f6feeb6c6ea90717c59fcf214ccb7bddba9877b86a, com.docker.compose.depends_on=, com.microsoft.version=15.0.4188.2, com.docker.compose.project=web, com.docker.compose.service=db, com.docker.compose.version=2.19.0)
Jul 04 10:11:08 myhost podman[79]: 2023-07-04 10:11:08.997655128 +0200 CEST m=+569.885996829 container init 8b89601e5e39200b1d3849be8ca1d832bd0574a51638e40ac33a6c3071b68370 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.docker.compose.version=2.19.0, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.service=db, com.microsoft.version=15.0.4188.2, com.docker.compose.oneoff=False, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.project=web, com.docker.compose.container-number=1, com.docker.compose.config-hash=fcde2100d6bb806bc59123f6feeb6c6ea90717c59fcf214ccb7bddba9877b86a, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.depends_on=, vendor=Microsoft, com.docker.compose.replace=c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f, com.microsoft.product=Microsoft SQL Server)
Jul 04 10:11:08 myhost podman[79]: 2023-07-04 10:11:08.998731129 +0200 CEST m=+569.887072930 container attach 8b89601e5e39200b1d3849be8ca1d832bd0574a51638e40ac33a6c3071b68370 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.docker.compose.depends_on=, com.docker.compose.container-number=1, com.microsoft.version=15.0.4188.2, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.project=web, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, vendor=Microsoft, com.docker.compose.service=db, com.docker.compose.oneoff=False, com.docker.compose.version=2.19.0, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.replace=c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f, com.docker.compose.config-hash=fcde2100d6bb806bc59123f6feeb6c6ea90717c59fcf214ccb7bddba9877b86a, com.microsoft.product=Microsoft SQL Server)
Jul 04 10:11:09 myhost web-db[538]: SQL Server 2019 will run as non-root by default.
Jul 04 10:11:09 myhost web-db[538]: This container is running as user mssql.
Jul 04 10:11:09 myhost web-db[538]: Your master database file is owned by mssql.
Jul 04 10:11:09 myhost web-db[538]: To learn more visit https://go.microsoft.com/fwlink/?linkid=2099216.
Jul 04 10:11:09 myhost web-db[538]: Starting database instance
Jul 04 10:11:09 myhost podman[79]: 2023-07-04 10:11:09.076027407 +0200 CEST m=+569.964369108 container start 8b89601e5e39200b1d3849be8ca1d832bd0574a51638e40ac33a6c3071b68370 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.docker.compose.container-number=1, vendor=Microsoft, com.docker.compose.config-hash=fcde2100d6bb806bc59123f6feeb6c6ea90717c59fcf214ccb7bddba9877b86a, com.docker.compose.version=2.19.0, com.microsoft.version=15.0.4188.2, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.oneoff=False, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.project=web, com.docker.compose.service=db, com.docker.compose.depends_on=, com.docker.compose.replace=c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f, com.microsoft.product=Microsoft SQL Server)
Jul 04 10:11:10 myhost web-db[538]: 2023-07-04 08:11:10.86 Server      Setup step is FORCE copying system data file 'C:\templatedata\model_replicatedmaster.mdf' to '/var/opt/mssql/data/model_replicatedmaster.mdf'.
Jul 04 10:11:10 myhost web-db[538]: [179B blob data]
Jul 04 10:11:10 myhost web-db[538]: [163B blob data]
Jul 04 10:11:10 myhost web-db[538]: [161B blob data]
Jul 04 10:11:11 myhost web-db[538]: [106B blob data]
Jul 04 10:11:11 myhost web-db[538]: [31B blob data]
Jul 04 10:11:11 myhost web-db[538]: [50B blob data]
Jul 04 10:11:11 myhost web-db[538]: [72B blob data]
Jul 04 10:11:11 myhost web-db[538]: [57B blob data]
Jul 04 10:11:11 myhost web-db[538]: [63B blob data]
Jul 04 10:11:11 myhost web-db[538]: [57B blob data]
Jul 04 10:11:11 myhost web-db[538]: [62B blob data]
Jul 04 10:11:11 myhost web-db[538]: [103B blob data]
Jul 04 10:11:11 myhost web-db[538]: [66B blob data]
Jul 04 10:11:11 myhost web-db[538]: [44B blob data]
Jul 04 10:11:11 myhost web-db[538]: [45B blob data]
Jul 04 10:11:11 myhost web-db[538]: [41B blob data]
Jul 04 10:11:11 myhost web-db[538]: [278B blob data]
Jul 04 10:11:11 myhost web-db[538]: [156B blob data]
Jul 04 10:11:11 myhost web-db[538]: [124B blob data]
Jul 04 10:11:11 myhost web-db[538]: [85B blob data]
Jul 04 10:11:11 myhost web-db[538]: [70B blob data]
Jul 04 10:11:11 myhost web-db[538]: [94B blob data]
Jul 04 10:11:11 myhost web-db[538]: [97B blob data]
Jul 04 10:11:11 myhost web-db[538]: [103B blob data]
Jul 04 10:11:11 myhost web-db[538]: [558B blob data]
Jul 04 10:11:11 myhost web-db[538]: [88B blob data]
Jul 04 10:11:11 myhost web-db[538]: [119B blob data]
Jul 04 10:11:11 myhost web-db[538]: [282B blob data]
Jul 04 10:11:11 myhost web-db[538]: [213B blob data]
Jul 04 10:11:11 myhost web-db[538]: [84B blob data]
Jul 04 10:11:11 myhost web-db[538]: [95B blob data]
Jul 04 10:11:11 myhost web-db[538]: [275B blob data]
Jul 04 10:11:11 myhost web-db[538]: [43B blob data]
Jul 04 10:11:11 myhost web-db[538]: [127B blob data]
Jul 04 10:11:11 myhost web-db[538]: [85B blob data]
Jul 04 10:11:11 myhost web-db[538]: [72B blob data]
Jul 04 10:11:11 myhost web-db[538]: [97B blob data]
Jul 04 10:11:11 myhost web-db[538]: [67B blob data]
Jul 04 10:11:11 myhost web-db[538]: [51B blob data]
Jul 04 10:11:11 myhost web-db[538]: [162B blob data]
Jul 04 10:11:11 myhost web-db[538]: [158B blob data]
Jul 04 10:11:11 myhost web-db[538]: [162B blob data]
Jul 04 10:11:11 myhost web-db[538]: [67B blob data]
Jul 04 10:11:11 myhost web-db[538]: [81B blob data]
Jul 04 10:11:11 myhost web-db[538]: [139B blob data]
Jul 04 10:11:11 myhost web-db[538]: [139B blob data]
Jul 04 10:11:11 myhost web-db[538]: [78B blob data]
Jul 04 10:11:11 myhost web-db[538]: [137B blob data]
Jul 04 10:11:11 myhost web-db[538]: [160B blob data]
Jul 04 10:11:11 myhost web-db[538]: [97B blob data]
Jul 04 10:11:11 myhost web-db[538]: [97B blob data]
Jul 04 10:11:11 myhost web-db[538]: [101B blob data]
Jul 04 10:11:11 myhost web-db[538]: [97B blob data]
Jul 04 10:11:11 myhost web-db[538]: [218B blob data]
Jul 04 10:11:11 myhost web-db[538]: [65B blob data]
Jul 04 10:11:11 myhost web-db[538]: [85B blob data]
Jul 04 10:11:11 myhost web-db[538]: [80B blob data]
Jul 04 10:11:11 myhost web-db[538]: [92B blob data]
Jul 04 10:11:11 myhost web-db[538]: [105B blob data]
Jul 04 10:11:11 myhost web-db[538]: [154B blob data]
Jul 04 10:11:11 myhost web-db[538]: [81B blob data]
Jul 04 10:11:11 myhost web-db[538]: [81B blob data]
Jul 04 10:11:11 myhost web-db[538]: [93B blob data]
Jul 04 10:11:11 myhost web-db[538]: [79B blob data]
Jul 04 10:11:11 myhost web-db[538]: [85B blob data]
Jul 04 10:11:11 myhost web-db[538]: [123B blob data]
Jul 04 10:11:11 myhost web-db[538]: [97B blob data]
Jul 04 10:11:11 myhost web-db[538]: [79B blob data]
Jul 04 10:11:12 myhost web-db[538]: [66B blob data]
Jul 04 10:11:12 myhost web-db[538]: [85B blob data]
Jul 04 10:11:12 myhost web-db[538]: [146B blob data]
Jul 04 10:11:12 myhost web-db[538]: [160B blob data]
Jul 04 10:11:12 myhost web-db[538]: [62B blob data]
Jul 04 10:11:12 myhost web-db[538]: [156B blob data]
Jul 04 10:11:12 myhost web-db[538]: [160B blob data]
Jul 04 10:11:13 myhost web-db[538]: [97B blob data]
Jul 04 10:11:13 myhost web-db[538]: [67B blob data]
Jul 04 10:11:13 myhost web-db[538]: [128B blob data]
Jul 04 10:11:14 myhost web-db[538]: [180B blob data]
Jul 04 10:11:14 myhost web-db[538]: [176B blob data]
Jul 04 10:11:14 myhost web-db[538]: [180B blob data]
Jul 04 10:11:14 myhost web-db[538]: [129B blob data]
Jul 04 10:11:14 myhost web-db[538]: [135B blob data]
Jul 04 10:11:14 myhost web-db[538]: [188B blob data]
Jul 04 10:11:14 myhost web-db[538]: [183B blob data]
Jul 04 10:11:14 myhost web-db[538]: [187B blob data]
Jul 04 10:11:14 myhost web-db[538]: [76B blob data]
Jul 04 10:11:14 myhost web-db[538]: [97B blob data]
Jul 04 10:11:14 myhost web-db[538]: [101B blob data]
Jul 04 10:11:14 myhost web-db[538]: [72B blob data]
Jul 04 10:11:14 myhost web-db[538]: [136B blob data]
Jul 04 10:11:14 myhost web-db[538]: [125B blob data]
Jul 04 10:13:35 myhost podman[79]: 2023-07-04 10:13:35.317863152 +0200 CEST m=+716.206204853 container init 65cf69d5a8794e8ee99cec2a12a1fbbac2874f0ddcb2b42150fc09b0f70c78d3 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=db, com.microsoft.product=Microsoft SQL Server, com.microsoft.version=15.0.4188.2, vendor=Microsoft)
Jul 04 10:13:35 myhost db[786]: SQL Server 2019 will run as non-root by default.
Jul 04 10:13:35 myhost db[786]: This container is running as user mssql.
Jul 04 10:13:35 myhost db[786]: Your master database file is owned by mssql.
Jul 04 10:13:35 myhost db[786]: To learn more visit https://go.microsoft.com/fwlink/?linkid=2099216.
Jul 04 10:13:35 myhost podman[79]: 2023-07-04 10:13:35.327771639 +0200 CEST m=+716.216113340 container start 65cf69d5a8794e8ee99cec2a12a1fbbac2874f0ddcb2b42150fc09b0f70c78d3 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=db, com.microsoft.product=Microsoft SQL Server, com.microsoft.version=15.0.4188.2, vendor=Microsoft)
Jul 04 10:13:36 myhost podman[79]: 2023-07-04 10:13:36.481045141 +0200 CEST m=+717.369386942 container init 2d0933e99e4a4e266bd962022ba1adb598da8fe1f927723e6ce64219bd3578b9 (image=myrepo.org/myproduct/boweb/dispo-backend:trunk, name=web-backend-dispo-legacy, org.opencontainers.image.ref.name=ubuntu, org.opencontainers.image.version=22.04)
Jul 04 10:13:36 myhost podman[79]: 2023-07-04 10:13:36.488365522 +0200 CEST m=+717.376707323 container start 2d0933e99e4a4e266bd962022ba1adb598da8fe1f927723e6ce64219bd3578b9 (image=myrepo.org/myproduct/boweb/dispo-backend:trunk, name=web-backend-dispo-legacy, org.opencontainers.image.ref.name=ubuntu, org.opencontainers.image.version=22.04)
Jul 04 10:13:36 myhost web-backend-dispo-legacy[909]: Using CATALINA_BASE:   /usr/local/tomcat
Jul 04 10:13:36 myhost web-backend-dispo-legacy[909]: Using CATALINA_HOME:   /usr/local/tomcat
Jul 04 10:13:36 myhost web-backend-dispo-legacy[909]: Using CATALINA_TMPDIR: /usr/local/tomcat/temp
Jul 04 10:13:36 myhost web-backend-dispo-legacy[909]: Using JRE_HOME:        /opt/java/openjdk
Jul 04 10:13:36 myhost web-backend-dispo-legacy[909]: Using CLASSPATH:       /usr/local/tomcat/bin/bootstrap.jar:/usr/local/tomcat/bin/tomcat-juli.jar
Jul 04 10:13:36 myhost web-backend-dispo-legacy[909]: Using CATALINA_OPTS:    -Ddbuser=mydbuser -Ddbpassword=mypass -DconnURL=jdbc:sqlserver://host.containers.internal\;databaseName=TC_MIGRATE_DB
Jul 04 10:13:36 myhost web-backend-dispo-legacy[909]: NOTE: Picked up JDK_JAVA_OPTIONS:  --add-opens=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.io=ALL-UNNAMED --add-opens=java.base/java.util=ALL-UNNAMED --add-opens=java.base/java.util.concurrent=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.112 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name:   Apache Tomcat/9.0.76
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.114 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Jun 5 2023 07:17:04 UTC
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.114 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 9.0.76.0
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.114 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.115 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            5.15.90.1-microsoft-standard-WSL2
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.115 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.115 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /opt/java/openjdk
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.115 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           11.0.19+7
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.115 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Eclipse Adoptium
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.115 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /usr/local/tomcat
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.116 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/local/tomcat
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.135 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.135 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.136 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util=ALL-UNNAMED
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.136 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util.concurrent=ALL-UNNAMED
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.136 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.136 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.136 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.136 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.137 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.137 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.137 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Ddbuser=mydbuser
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.137 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Ddbpassword=mypass
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.137 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -DconnURL=jdbc:sqlserver://host.containers.internal;databaseName=TC_MIGRATE_DB
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.138 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.138 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.138 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.138 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.151 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded Apache Tomcat Native library [1.2.37] using APR version [1.7.0].
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.151 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true], UDS [true].
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.151 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.163 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 3.0.2 15 Mar 2022]
Jul 04 10:13:37 myhost db[786]: 2023-07-04 08:13:37.23 Server      Setup step is FORCE copying system data file 'C:\templatedata\model_replicatedmaster.mdf' to '/var/opt/mssql/data/model_replicatedmaster.mdf'.
Jul 04 10:13:37 myhost db[786]: [179B blob data]
Jul 04 10:13:37 myhost db[786]: [163B blob data]
Jul 04 10:13:37 myhost db[786]: [161B blob data]
Jul 04 10:13:37 myhost db[786]: [106B blob data]
Jul 04 10:13:37 myhost db[786]: [31B blob data]
Jul 04 10:13:37 myhost db[786]: [50B blob data]
Jul 04 10:13:37 myhost db[786]: [72B blob data]
Jul 04 10:13:37 myhost db[786]: [57B blob data]
Jul 04 10:13:37 myhost db[786]: [63B blob data]
Jul 04 10:13:37 myhost db[786]: [57B blob data]
Jul 04 10:13:37 myhost db[786]: [62B blob data]
Jul 04 10:13:37 myhost db[786]: [103B blob data]
Jul 04 10:13:37 myhost db[786]: [66B blob data]
Jul 04 10:13:37 myhost db[786]: [44B blob data]
Jul 04 10:13:37 myhost db[786]: [45B blob data]
Jul 04 10:13:37 myhost db[786]: [41B blob data]
Jul 04 10:13:37 myhost db[786]: [278B blob data]
Jul 04 10:13:37 myhost db[786]: [156B blob data]
Jul 04 10:13:37 myhost db[786]: [124B blob data]
Jul 04 10:13:37 myhost db[786]: [85B blob data]
Jul 04 10:13:37 myhost db[786]: [70B blob data]
Jul 04 10:13:37 myhost db[786]: [94B blob data]
Jul 04 10:13:37 myhost db[786]: [97B blob data]
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.479 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.511 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [621] milliseconds
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.564 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.564 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.76]
Jul 04 10:13:37 myhost db[786]: [103B blob data]
Jul 04 10:13:37 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:37.593 INFO [main] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/usr/local/tomcat/webapps/ROOT.war]
Jul 04 10:13:37 myhost db[786]: [558B blob data]
Jul 04 10:13:37 myhost db[786]: [88B blob data]
Jul 04 10:13:37 myhost db[786]: [119B blob data]
Jul 04 10:13:37 myhost db[786]: [282B blob data]
Jul 04 10:13:37 myhost db[786]: [213B blob data]
Jul 04 10:13:37 myhost db[786]: [84B blob data]
Jul 04 10:13:37 myhost db[786]: [95B blob data]
Jul 04 10:13:37 myhost db[786]: [275B blob data]
Jul 04 10:13:37 myhost db[786]: [43B blob data]
Jul 04 10:13:37 myhost db[786]: [127B blob data]
Jul 04 10:13:37 myhost db[786]: [85B blob data]
Jul 04 10:13:37 myhost db[786]: [72B blob data]
Jul 04 10:13:37 myhost db[786]: [97B blob data]
Jul 04 10:13:37 myhost db[786]: [67B blob data]
Jul 04 10:13:37 myhost db[786]: [51B blob data]
Jul 04 10:13:38 myhost db[786]: [67B blob data]
Jul 04 10:13:38 myhost db[786]: [162B blob data]
Jul 04 10:13:38 myhost db[786]: [158B blob data]
Jul 04 10:13:38 myhost db[786]: [162B blob data]
Jul 04 10:13:38 myhost db[786]: [81B blob data]
Jul 04 10:13:38 myhost db[786]: [139B blob data]
Jul 04 10:13:38 myhost db[786]: [139B blob data]
Jul 04 10:13:38 myhost db[786]: [78B blob data]
Jul 04 10:13:38 myhost db[786]: [137B blob data]
Jul 04 10:13:38 myhost db[786]: [160B blob data]
Jul 04 10:13:38 myhost db[786]: [101B blob data]
Jul 04 10:13:38 myhost db[786]: [97B blob data]
Jul 04 10:13:38 myhost db[786]: [218B blob data]
Jul 04 10:13:38 myhost db[786]: [97B blob data]
Jul 04 10:13:38 myhost db[786]: [97B blob data]
Jul 04 10:13:38 myhost db[786]: [80B blob data]
Jul 04 10:13:38 myhost db[786]: [85B blob data]
Jul 04 10:13:38 myhost db[786]: [65B blob data]
Jul 04 10:13:38 myhost db[786]: [92B blob data]
Jul 04 10:13:38 myhost db[786]: [154B blob data]
Jul 04 10:13:38 myhost db[786]: [97B blob data]
Jul 04 10:13:38 myhost db[786]: [66B blob data]
Jul 04 10:13:38 myhost db[786]: [128B blob data]
Jul 04 10:13:38 myhost db[786]: [135B blob data]
Jul 04 10:13:38 myhost db[786]: [105B blob data]
Jul 04 10:13:38 myhost db[786]: [81B blob data]
Jul 04 10:13:38 myhost db[786]: [81B blob data]
Jul 04 10:13:38 myhost db[786]: [62B blob data]
Jul 04 10:13:38 myhost db[786]: [79B blob data]
Jul 04 10:13:38 myhost db[786]: [85B blob data]
Jul 04 10:13:38 myhost db[786]: [123B blob data]
Jul 04 10:13:38 myhost db[786]: [79B blob data]
Jul 04 10:13:38 myhost db[786]: [85B blob data]
Jul 04 10:13:38 myhost db[786]: [180B blob data]
Jul 04 10:13:38 myhost db[786]: [146B blob data]
Jul 04 10:13:38 myhost db[786]: [188B blob data]
Jul 04 10:13:38 myhost db[786]: [176B blob data]
Jul 04 10:13:38 myhost db[786]: [93B blob data]
Jul 04 10:13:38 myhost db[786]: [129B blob data]
Jul 04 10:13:38 myhost db[786]: [97B blob data]
Jul 04 10:13:38 myhost db[786]: [67B blob data]
Jul 04 10:13:38 myhost db[786]: [183B blob data]
Jul 04 10:13:38 myhost db[786]: [187B blob data]
Jul 04 10:13:38 myhost db[786]: [136B blob data]
Jul 04 10:13:38 myhost db[786]: [76B blob data]
Jul 04 10:13:38 myhost db[786]: [97B blob data]
Jul 04 10:13:38 myhost db[786]: [101B blob data]
Jul 04 10:13:38 myhost db[786]: [72B blob data]
Jul 04 10:13:38 myhost db[786]: [125B blob data]
Jul 04 10:13:40 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:40.057 INFO [main] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Jul 04 10:13:45 myhost web-backend-dispo-legacy[909]: IOWeb 2023-07-04 08:13:45,071 INFO  [18 - Thread-1]: UploadExecutor startet running.
Jul 04 10:13:45 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:45.968 INFO [main] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/usr/local/tomcat/webapps/ROOT.war] has finished in [8,375] ms
Jul 04 10:13:45 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:45.974 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
Jul 04 10:13:45 myhost web-backend-dispo-legacy[909]: 04-Jul-2023 08:13:45.984 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [8472] milliseconds
Jul 04 10:14:26 myhost web-db[538]: 
Jul 04 10:14:26 myhost podman[79]: 2023-07-04 10:14:26.676226768 +0200 CEST m=+767.564568469 container died 8b89601e5e39200b1d3849be8ca1d832bd0574a51638e40ac33a6c3071b68370 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, vendor=Microsoft, com.docker.compose.version=2.19.0, com.microsoft.product=Microsoft SQL Server, com.docker.compose.config-hash=fcde2100d6bb806bc59123f6feeb6c6ea90717c59fcf214ccb7bddba9877b86a, com.docker.compose.depends_on=, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.project=web, com.docker.compose.replace=c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f, com.microsoft.version=15.0.4188.2, com.docker.compose.oneoff=False, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.container-number=1, com.docker.compose.service=db)
Jul 04 10:14:27 myhost podman[79]: 2023-07-04 10:14:27.063913975 +0200 CEST m=+767.952255676 container cleanup 8b89601e5e39200b1d3849be8ca1d832bd0574a51638e40ac33a6c3071b68370 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.microsoft.product=Microsoft SQL Server, com.docker.compose.version=2.19.0, com.docker.compose.config-hash=fcde2100d6bb806bc59123f6feeb6c6ea90717c59fcf214ccb7bddba9877b86a, com.docker.compose.container-number=1, vendor=Microsoft, com.docker.compose.depends_on=, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.oneoff=False, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.microsoft.version=15.0.4188.2, com.docker.compose.replace=c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f, com.docker.compose.project=web, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.service=db)
Jul 04 10:14:27 myhost podman[1093]: 2023-07-04 10:14:27.065178585 +0200 CEST m=+0.394165460 container cleanup 8b89601e5e39200b1d3849be8ca1d832bd0574a51638e40ac33a6c3071b68370 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.version=2.19.0, com.docker.compose.project=web, com.docker.compose.service=db, com.docker.compose.container-number=1, com.docker.compose.oneoff=False, com.microsoft.product=Microsoft SQL Server, com.microsoft.version=15.0.4188.2, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.depends_on=, com.docker.compose.replace=c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f, vendor=Microsoft, com.docker.compose.config-hash=fcde2100d6bb806bc59123f6feeb6c6ea90717c59fcf214ccb7bddba9877b86a)
Jul 04 10:15:01 myhost podman[79]: 2023-07-04 10:15:01.959783642 +0200 CEST m=+802.848125343 container create 6b3d345472fc1d2169b402b30b3aafadf4b481b4597da4f09718dc81dcc19e57 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=8b89601e5e39_web-db, com.docker.compose.oneoff=False, com.docker.compose.replace=8b89601e5e39200b1d3849be8ca1d832bd0574a51638e40ac33a6c3071b68370, com.docker.compose.project=web, com.docker.compose.container-number=1, com.microsoft.version=15.0.4188.2, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.config-hash=85a60d991c75cce172de3efd9673360c523608bb5601d89cfdd8a728c23a2fd1, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.version=2.19.0, com.docker.compose.service=db, vendor=Microsoft, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.depends_on=, com.microsoft.product=Microsoft SQL Server)
Jul 04 10:15:02 myhost podman[79]: 2023-07-04 10:15:02.232423732 +0200 CEST m=+803.120765433 container remove 8b89601e5e39200b1d3849be8ca1d832bd0574a51638e40ac33a6c3071b68370 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.microsoft.product=Microsoft SQL Server, com.docker.compose.depends_on=, com.docker.compose.config-hash=fcde2100d6bb806bc59123f6feeb6c6ea90717c59fcf214ccb7bddba9877b86a, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, vendor=Microsoft, com.docker.compose.project=web, com.microsoft.version=15.0.4188.2, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.service=db, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.replace=c06cabe4fa8b67b8fdcf6af2f97a6b3dd350e08ba5182dc298178edd9fbff89f, com.docker.compose.oneoff=False, com.docker.compose.version=2.19.0, com.docker.compose.container-number=1)
Jul 04 10:15:02 myhost podman[79]: 2023-07-04 10:15:02.248087357 +0200 CEST m=+803.136429058 container rename 6b3d345472fc1d2169b402b30b3aafadf4b481b4597da4f09718dc81dcc19e57 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.docker.compose.replace=8b89601e5e39200b1d3849be8ca1d832bd0574a51638e40ac33a6c3071b68370, com.docker.compose.config-hash=85a60d991c75cce172de3efd9673360c523608bb5601d89cfdd8a728c23a2fd1, com.docker.compose.depends_on=, com.docker.compose.service=db, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.container-number=1, com.docker.compose.version=2.19.0, com.microsoft.product=Microsoft SQL Server, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.project=web, com.docker.compose.oneoff=False, com.microsoft.version=15.0.4188.2, vendor=Microsoft, com.docker.compose.project.working_dir=C:\Library\myproduct\Web)
Jul 04 10:15:02 myhost podman[79]: 2023-07-04 10:15:02.480994528 +0200 CEST m=+803.369336229 container init eb0ea21f18e4b50356c4b5b897f5e5556bf941194c2adca221cdfb2e47acca28 (image=docker.io/library/web-backend-aoiam:latest, name=web-backend-aoiam, com.docker.compose.project=web, com.docker.compose.version=2.19.0, com.docker.compose.config-hash=ab446346c5625b4c4db13e6ad1b10a348d4f4fa4418a957148e4f5ab9bae7a7b, com.docker.compose.oneoff=False, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, io.buildah.version=1.30.0, com.docker.compose.container-number=1, com.docker.compose.image.builder=classic, com.docker.compose.image=sha256:f8a1e37998ba4cb01961f548f17e31afb9668c525cd6a46efb09a72c5c5b4958, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.service=backend-aoiam, com.docker.compose.depends_on=)
Jul 04 10:15:02 myhost podman[79]: 2023-07-04 10:15:02.48118863 +0200 CEST m=+803.369530331 container attach eb0ea21f18e4b50356c4b5b897f5e5556bf941194c2adca221cdfb2e47acca28 (image=docker.io/library/web-backend-aoiam:latest, name=web-backend-aoiam, com.docker.compose.depends_on=, com.docker.compose.image=sha256:f8a1e37998ba4cb01961f548f17e31afb9668c525cd6a46efb09a72c5c5b4958, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, io.buildah.version=1.30.0, com.docker.compose.container-number=1, com.docker.compose.project=web, com.docker.compose.service=backend-aoiam, com.docker.compose.version=2.19.0, com.docker.compose.config-hash=ab446346c5625b4c4db13e6ad1b10a348d4f4fa4418a957148e4f5ab9bae7a7b, com.docker.compose.image.builder=classic, com.docker.compose.oneoff=False, com.docker.compose.project.working_dir=C:\Library\myproduct\Web)
Jul 04 10:15:02 myhost podman[79]: 2023-07-04 10:15:02.589756202 +0200 CEST m=+803.478097903 container init d261796415d99afdcd9ffdcdf033b1eac3f1ba28393786fd464197c6ef3e5597 (image=myrepo.org/myproduct/boweb/dispo-backend:trunk, name=web-backend-dispo, com.docker.compose.service=backend-dispo, com.docker.compose.version=2.19.0, org.opencontainers.image.ref.name=ubuntu, com.docker.compose.depends_on=, com.docker.compose.oneoff=False, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.image=sha256:80fa23f16097347664f088faa6acefb558d35eb2e4675b1c44857e431a8fadd3, com.docker.compose.config-hash=3243e19184825fa3f0edd747edd5fc915382854422fa789d9d25341e55bced7d, com.docker.compose.container-number=1, com.docker.compose.project=web, org.opencontainers.image.version=22.04)
Jul 04 10:15:02 myhost podman[79]: 2023-07-04 10:15:02.589916903 +0200 CEST m=+803.478258604 container attach d261796415d99afdcd9ffdcdf033b1eac3f1ba28393786fd464197c6ef3e5597 (image=myrepo.org/myproduct/boweb/dispo-backend:trunk, name=web-backend-dispo, org.opencontainers.image.version=22.04, com.docker.compose.version=2.19.0, com.docker.compose.project=web, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.container-number=1, com.docker.compose.depends_on=, com.docker.compose.oneoff=False, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, org.opencontainers.image.ref.name=ubuntu, com.docker.compose.config-hash=3243e19184825fa3f0edd747edd5fc915382854422fa789d9d25341e55bced7d, com.docker.compose.image=sha256:80fa23f16097347664f088faa6acefb558d35eb2e4675b1c44857e431a8fadd3, com.docker.compose.service=backend-dispo)
Jul 04 10:15:02 myhost podman[79]: 2023-07-04 10:15:02.793406238 +0200 CEST m=+803.681748039 container init 5400f110f1e62ab16f7bba4b45007cfe70c352e4039450bf487def00cfa574de (image=myrepo.org/linux/bmhttpcommand:trunk, name=web-backend-http-command, com.docker.compose.image=sha256:3f158e58a0a9e9bc84839383b01a108528ee754411144eac0e77a582c23c9516, com.docker.compose.oneoff=False, com.docker.compose.container-number=1, com.docker.compose.service=backend-http-command, com.docker.compose.depends_on=, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.version=2.19.0, com.docker.compose.config-hash=3940b37debc82767d5b1d9554e79354918938cec033b64c5b283a99bf00e6768, com.docker.compose.project=web, com.docker.compose.project.working_dir=C:\Library\myproduct\Web)
Jul 04 10:15:02 myhost podman[79]: 2023-07-04 10:15:02.793557739 +0200 CEST m=+803.681899440 container attach 5400f110f1e62ab16f7bba4b45007cfe70c352e4039450bf487def00cfa574de (image=myrepo.org/linux/bmhttpcommand:trunk, name=web-backend-http-command, com.docker.compose.container-number=1, com.docker.compose.image=sha256:3f158e58a0a9e9bc84839383b01a108528ee754411144eac0e77a582c23c9516, com.docker.compose.oneoff=False, com.docker.compose.project=web, com.docker.compose.service=backend-http-command, com.docker.compose.depends_on=, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.version=2.19.0, com.docker.compose.config-hash=3940b37debc82767d5b1d9554e79354918938cec033b64c5b283a99bf00e6768, com.docker.compose.project.working_dir=C:\Library\myproduct\Web)
Jul 04 10:15:02 myhost podman[79]: 2023-07-04 10:15:02.891111023 +0200 CEST m=+803.779452724 container init fe944f84d8688c0cb084ab71d3e895a515fb88586436d90ba01650d8859de332 (image=docker.io/library/web-backend-nestjs:latest, name=web-backend-nestjs, com.docker.compose.service=backend-nestjs, com.docker.compose.version=2.19.0, com.docker.compose.config-hash=e423eaffc70e2fb02bfdc1440011b9212e77ad3a1306db7297ed893d1ad45b73, com.docker.compose.depends_on=, com.docker.compose.oneoff=False, com.docker.compose.project=web, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, io.buildah.version=1.30.0, com.docker.compose.container-number=1, com.docker.compose.image=sha256:d3762546d7304e25132096fd9f07c45ee347eb696808fcd10cb49aa1728909ac, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.image.builder=classic)
Jul 04 10:15:02 myhost podman[79]: 2023-07-04 10:15:02.891415125 +0200 CEST m=+803.779756926 container attach fe944f84d8688c0cb084ab71d3e895a515fb88586436d90ba01650d8859de332 (image=docker.io/library/web-backend-nestjs:latest, name=web-backend-nestjs, com.docker.compose.container-number=1, com.docker.compose.depends_on=, com.docker.compose.version=2.19.0, io.buildah.version=1.30.0, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.service=backend-nestjs, com.docker.compose.config-hash=e423eaffc70e2fb02bfdc1440011b9212e77ad3a1306db7297ed893d1ad45b73, com.docker.compose.image=sha256:d3762546d7304e25132096fd9f07c45ee347eb696808fcd10cb49aa1728909ac, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.image.builder=classic, com.docker.compose.oneoff=False, com.docker.compose.project=web)
Jul 04 10:15:03 myhost podman[79]: 2023-07-04 10:15:03.121420873 +0200 CEST m=+804.009762674 container init 6b3d345472fc1d2169b402b30b3aafadf4b481b4597da4f09718dc81dcc19e57 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.docker.compose.version=2.19.0, com.microsoft.version=15.0.4188.2, vendor=Microsoft, com.docker.compose.container-number=1, com.docker.compose.oneoff=False, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.microsoft.product=Microsoft SQL Server, com.docker.compose.project=web, com.docker.compose.depends_on=, com.docker.compose.config-hash=85a60d991c75cce172de3efd9673360c523608bb5601d89cfdd8a728c23a2fd1, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.service=db, com.docker.compose.replace=8b89601e5e39200b1d3849be8ca1d832bd0574a51638e40ac33a6c3071b68370)
Jul 04 10:15:03 myhost podman[79]: 2023-07-04 10:15:03.121656875 +0200 CEST m=+804.009998576 container attach 6b3d345472fc1d2169b402b30b3aafadf4b481b4597da4f09718dc81dcc19e57 (image=myrepo.org/myproduct/mssql/with-data/2019-latest:trunk, name=web-db, com.docker.compose.replace=8b89601e5e39200b1d3849be8ca1d832bd0574a51638e40ac33a6c3071b68370, vendor=Microsoft, com.docker.compose.project.config_files=C:\Library\myproduct\Web\docker-compose.integration-tests.yml, com.docker.compose.oneoff=False, com.docker.compose.project.working_dir=C:\Library\myproduct\Web, com.docker.compose.image=sha256:787d571ba9cba2b028aa8543bcda7d5cbfdf57ab743a628df4df84bbf2e8ae7e, com.docker.compose.version=2.19.0, com.docker.compose.config-hash=85a60d991c75cce172de3efd9673360c523608bb5601d89cfdd8a728c23a2fd1, com.microsoft.version=15.0.4188.2, com.docker.compose.container-number=1, com.microsoft.product=Microsoft SQL Server, com.docker.compose.depends_on=, com.docker.compose.project=web, com.docker.compose.service=db)
Jul 04 10:20:34 myhost db[786]: [157B blob data]
Jul 04 10:20:34 myhost db[786]: [196B blob data]
-- Boot b934560423e3441cabee5a4d2e05f0eb --
Jul 04 12:08:51 myhost systemd[43]: Starting podman.service - Podman API Service...
Jul 04 12:08:51 myhost systemd[43]: Started podman.service - Podman API Service.

PS: You'll notice that a container (ms sql server) is logging out stuff that appears as blob data; indeed there's an encoding issue with it, but I don't think this issue is related, since the unresponsiveness also occurs without starting this container.

@informeti
Copy link
Author

The issue occurred again, this time under slightly different circumstances:

  • I used Podman this morning to create and run two containers.
  • I left Podman and these two containers unused (but still running) for about 1-2 hours.
  • I wanted to build a docker-compose stack using DOCKER_BUILDKIT=0 docker-compose build
    • This normally works perfectly. I have to disable the usage of BuildKit because it doesn't seem to work with Podman (but that'd be another issue, if it is one at all).

This time, I have no logging: The log file stops on Wednesday the 5th, even though I used Podman yesterday (Thursday the 6th) and today (Friday the 7th).

Just like in the previously reported case, the socket seems to be running, the service isn't, and the CLI log remains stuck at:

time="2023-07-04T10:46:46+02:00" level=debug msg="DoRequest Method: GET URI: http://d/v4.5.1/libpod/_ping"

● podman.socket - Podman API Socket
     Loaded: loaded (/usr/lib/systemd/system/podman.socket; enabled
; preset: disabled)
     Active: active (listening) since Fri 2023-07-07 07:14:50 CEST; 5h 6min ago
   Triggers: ● podman.service
       Docs: man:podman-system-service(1)
     Listen: /run/podman/podman.sock (Stream)
     CGroup: /system.slice/podman.socket

Jul 07 07:14:50 myhost systemd[1]: Listening on podman.socket - Podman API Socket.

○ podman.service - Podman API Service
     Loaded: loaded (/usr/lib/systemd/system/podman.service;
disabled; preset: disabled)
     Active: inactive (dead)
TriggeredBy: ● podman.socket
       Docs: man:podman-system-service(1)

@baude
Copy link
Member

baude commented Jul 13, 2023

am I misremembering or was there not an issue with 4.5.0, which is why we did 4.5.1 so quickly ?

@github-actions
Copy link

A friendly reminder that this issue had no activity for 30 days.

@carlosrodfern
Copy link

carlosrodfern commented Aug 15, 2023 •
edited
Loading

@informeti , perhaps, it is like this one: #19625
...which appears to be a systemd issue: systemd/systemd#28843

@vrothberg
Copy link
Member

@informeti , perhaps, it is like this one: #19625 ...which appears to be a systemd issue: systemd/systemd#28843

Yes, this looks fixed by it. I am closing as it seems to be fixed in systemd.

@github-actions github-actions bot added the locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. label Dec 4, 2023
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Dec 4, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
kind/bug Categorizes issue or PR as related to a bug. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. machine windows issue/bug on Windows
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@benoitf @baude @carlosrodfern @vrothberg @Luap99 @informeti