State cache validity check is flaky

[onukristo]

I noticed, that composeUp sometimes takes 4-5 seconds, even when the containers are running from previous execution.
At other times, it is very fast, less than half a second.

On slow runs, the following is logged: "Current and cached states are different, cannot use the cached service infos.", after which some slow steps, including slow tcp checks, are done.

I realised, that the check here is a bit naive, not considering, that the arrays can have a different order.

For example, first cache state:

[Command:"docker-entrypoint.s…", CreatedAt:2023-12-13 10:08:48 +0200 EET, ExitCode:0, Health:, ID:48485d159557, Image:mariadb:10.4.27, LocalVolumes:1, Mounts:9d32a44f2b12f4…, Name:wise-kafka-processor-mariadb-1, Names:wise-kafka-processor-mariadb-1, Networks:wise-kafka-processor_default, Ports:0.0.0.0:44359->3306/tcp, Publishers:[[URL:0.0.0.0, TargetPort:3306, PublishedPort:44359, Protocol:tcp]], Service:mariadb, Size:0B, State:running, Status:Up]     [Command:"docker-entrypoint.s…", CreatedAt:2023-12-13 10:08:48 +0200 EET, ExitCode:0, Health:, ID:fd2671a506dd, Image:postgres:14, LocalVolumes:1, Mounts:d4bed348d71737…, Name:wise-kafka-processor-postgres-1, Names:wise-kafka-processor-postgres-1, Networks:wise-kafka-processor_default, Ports:0.0.0.0:62682->5432/tcp, Publishers:[[URL:0.0.0.0, TargetPort:5432, PublishedPort:62682, Protocol:tcp]], Service:postgres, Size:0B, State:running, Status:Up]      [Command:"/docker-entrypoint.…", CreatedAt:2023-12-13 10:08:48 +0200 EET, ExitCode:0, Health:, ID:a8eca8e46ecf, Image:zookeeper:3.7.1, LocalVolumes:3, Mounts:ac8a97f7ce79f3…,7111d5ab0ca1f2…,1fd0fecccf9c54…, Name:wise-kafka-processor-zookeeper-1, Names:wise-kafka-processor-zookeeper-1, Networks:wise-kafka-processor_default, Ports:2888/tcp, 3888/tcp, 8080/tcp, 0.0.0.0:59782->2181/tcp, Publishers:[[URL:0.0.0.0, TargetPort:2181, PublishedPort:59782, Protocol:tcp], [URL:, TargetPort:2888, PublishedPort:0, Protocol:tcp], [URL:, TargetPort:3888, PublishedPort:0, Protocol:tcp], [URL:, TargetPort:8080, PublishedPort:0, Protocol:tcp]], Service:zookeeper, Size:0B, State:running, Status:Up] [Command:"start-kafka.sh", CreatedAt:2023-12-13 10:08:48 +0200 EET, ExitCode:0, Health:, ID:eea0468a40d5, Image:wurstmeister/kafka:2.12-2.4.1, LocalVolumes:1, Mounts:15320d4b7b223e…,/run/host-serv…, Name:wise_kafka_processor_kafka, Names:wise_kafka_processor_kafka, Networks:wise-kafka-processor_default, Ports:0.0.0.0:49178->9092/tcp, Publishers:[[URL:0.0.0.0, TargetPort:9092, PublishedPort:49178, Protocol:tcp]], Service:kafka, Size:0B, State:running, Status:Up]name: wise-kafka-processor

and second cache state:

[Command:"docker-entrypoint.s…", CreatedAt:2023-12-13 10:08:48 +0200 EET, ExitCode:0, Health:, ID:48485d159557, Image:mariadb:10.4.27, LocalVolumes:1, Mounts:9d32a44f2b12f4…, Name:wise-kafka-processor-mariadb-1, Names:wise-kafka-processor-mariadb-1, Networks:wise-kafka-processor_default, Ports:0.0.0.0:44359->3306/tcp, Publishers:[[URL:0.0.0.0, TargetPort:3306, PublishedPort:44359, Protocol:tcp]], Service:mariadb, Size:0B, State:running, Status:Up]     [Command:"docker-entrypoint.s…", CreatedAt:2023-12-13 10:08:48 +0200 EET, ExitCode:0, Health:, ID:fd2671a506dd, Image:postgres:14, LocalVolumes:1, Mounts:d4bed348d71737…, Name:wise-kafka-processor-postgres-1, Names:wise-kafka-processor-postgres-1, Networks:wise-kafka-processor_default, Ports:0.0.0.0:62682->5432/tcp, Publishers:[[URL:0.0.0.0, TargetPort:5432, PublishedPort:62682, Protocol:tcp]], Service:postgres, Size:0B, State:running, Status:Up]      [Command:"/docker-entrypoint.…", CreatedAt:2023-12-13 10:08:48 +0200 EET, ExitCode:0, Health:, ID:a8eca8e46ecf, Image:zookeeper:3.7.1, LocalVolumes:3, Mounts:1fd0fecccf9c54…,ac8a97f7ce79f3…,7111d5ab0ca1f2…, Name:wise-kafka-processor-zookeeper-1, Names:wise-kafka-processor-zookeeper-1, Networks:wise-kafka-processor_default, Ports:2888/tcp, 3888/tcp, 8080/tcp, 0.0.0.0:59782->2181/tcp, Publishers:[[URL:0.0.0.0, TargetPort:2181, PublishedPort:59782, Protocol:tcp], [URL:, TargetPort:2888, PublishedPort:0, Protocol:tcp], [URL:, TargetPort:3888, PublishedPort:0, Protocol:tcp], [URL:, TargetPort:8080, PublishedPort:0, Protocol:tcp]], Service:zookeeper, Size:0B, State:running, Status:Up] [Command:"start-kafka.sh", CreatedAt:2023-12-13 10:08:48 +0200 EET, ExitCode:0, Health:, ID:eea0468a40d5, Image:wurstmeister/kafka:2.12-2.4.1, LocalVolumes:1, Mounts:15320d4b7b223e…,/run/host-serv…, Name:wise_kafka_processor_kafka, Names:wise_kafka_processor_kafka, Networks:wise-kafka-processor_default, Ports:0.0.0.0:49178->9092/tcp, Publishers:[[URL:0.0.0.0, TargetPort:9092, PublishedPort:49178, Protocol:tcp]], Service:kafka, Size:0B, State:running, Status:Up]name: wise-kafka-processor

are semantically the same, however have a order difference of "Mounts:ac8a97f7ce79f3…,7111d5ab0ca1f2…,1fd0fecccf9c54…" vs "Mounts:1fd0fecccf9c54…,ac8a97f7ce79f3…,7111d5ab0ca1f2...".

Expected behaviours:

1. Use cached state, when semantically nothing changes between the runs.
2. When order of mounts is different, still consider the cached state equal to current state.

In any case, this is a minor thing. Thanks for the great library.

Appendix #1: fast run logs:

Dec 13 10:30:54 
Dec 13 10:30:54 > Task :composeUp
Dec 13 10:30:54 Cached services infos loaded while 'stopContainers' is set to 'false'.
Dec 13 10:30:54 +----------------------------+----------------+-----------------+
Dec 13 10:30:54 | Name                       | Container Port | Mapping         |
Dec 13 10:30:54 +----------------------------+----------------+-----------------+
Dec 13 10:30:54 | wise_kafka_processor_kafka | 9092           | localhost:49178 |
Dec 13 10:30:54 +----------------------------+----------------+-----------------+
Dec 13 10:30:54 | mariadb-1                  | 3306           | localhost:44359 |
Dec 13 10:30:54 +----------------------------+----------------+-----------------+
Dec 13 10:30:54 | postgres-1                 | 5432           | localhost:62682 |
Dec 13 10:30:54 +----------------------------+----------------+-----------------+
Dec 13 10:30:54 | zookeeper-1                | 2181           | localhost:59782 |
Dec 13 10:30:54 +----------------------------+----------------+-----------------+
Dec 13 10:30:54 
Dec 13 10:30:54 > Task :composeDownForcedOnFailure SKIPPED
Dec 13 10:30:54 
Dec 13 10:30:54 Deprecated Gradle features were used in this build, making it incompatible with Gradle 9.0.
Dec 13 10:30:54 
Dec 13 10:30:54 You can use '--warning-mode all' to show the individual deprecation warnings and determine if they come from your own scripts or plugins.
Dec 13 10:30:54 
Dec 13 10:30:54 For more on this, please refer to https://docs.gradle.org/8.5/userguide/command_line_interface.html#sec:command_line_warnings in the Gradle documentation.
Dec 13 10:30:54 
Dec 13 10:30:54 BUILD SUCCESSFUL in 662ms
Dec 13 10:30:54 1 actionable task: 1 executed

Appendix #2: slow run logs:

Dec 13 10:31:55 
Dec 13 10:31:55 > Task :composeUp
Dec 13 10:31:55 Current and cached states are different, cannot use the cached service infos.
Dec 13 10:31:55 Will use localhost as host of kafka
Dec 13 10:31:55 Will use localhost as host of mariadb
Dec 13 10:31:55 Will use localhost as host of postgres
Dec 13 10:31:55 Will use localhost as host of zookeeper
Dec 13 10:31:55 Probing TCP socket on localhost:49178 of 'wise_kafka_processor_kafka'
Dec 13 10:31:55 TCP socket on localhost:49178 of 'wise_kafka_processor_kafka' is ready
Dec 13 10:31:55 Probing TCP socket on localhost:44359 of 'mariadb-1'
Dec 13 10:31:55 TCP socket on localhost:44359 of 'mariadb-1' is ready
Dec 13 10:31:55 Probing TCP socket on localhost:62682 of 'postgres-1'
Dec 13 10:31:56 TCP socket on localhost:62682 of 'postgres-1' is ready
Dec 13 10:31:56 Probing TCP socket on localhost:59782 of 'zookeeper-1'
Dec 13 10:31:57 TCP socket on localhost:59782 of 'zookeeper-1' is ready
Dec 13 10:31:57 +----------------------------+----------------+-----------------+
Dec 13 10:31:57 | Name                       | Container Port | Mapping         |
Dec 13 10:31:57 +----------------------------+----------------+-----------------+
Dec 13 10:31:57 | wise_kafka_processor_kafka | 9092           | localhost:49178 |
Dec 13 10:31:57 +----------------------------+----------------+-----------------+
Dec 13 10:31:57 | mariadb-1                  | 3306           | localhost:44359 |
Dec 13 10:31:57 +----------------------------+----------------+-----------------+
Dec 13 10:31:57 | postgres-1                 | 5432           | localhost:62682 |
Dec 13 10:31:57 +----------------------------+----------------+-----------------+
Dec 13 10:31:57 | zookeeper-1                | 2181           | localhost:59782 |
Dec 13 10:31:57 +----------------------------+----------------+-----------------+
Dec 13 10:31:57 
Dec 13 10:31:57 > Task :composeDownForcedOnFailure SKIPPED
Dec 13 10:31:57 
Dec 13 10:31:57 Deprecated Gradle features were used in this build, making it incompatible with Gradle 9.0.
Dec 13 10:31:57 
Dec 13 10:31:57 You can use '--warning-mode all' to show the individual deprecation warnings and determine if they come from your own scripts or plugins.
Dec 13 10:31:57 
Dec 13 10:31:57 For more on this, please refer to https://docs.gradle.org/8.5/userguide/command_line_interface.html#sec:command_line_warnings in the Gradle documentation.
Dec 13 10:31:57 
Dec 13 10:31:57 BUILD SUCCESSFUL in 4s
Dec 13 10:31:57 1 actionable task: 1 executed

[augi]

Hello, thank you very much for reporting this! 👍 Agree that the current implementation is naïve, just please refer to getStateforCache method - this is where the state is computed, and there is already some kind of normalization.

So feel free to prepare a PR that would improve this behavior 🙏

Also, please note that there is already removal of the Labels field, but it is not so important for the container. I would prefer a more sophisticates solution for the Mounts field, for example just order the array.

[tom-wozniakowski-tw]

I have raised a PR to fix this bug: #468

Would appreciate a review and a merge if you're happy @augi !

[piotrminkina]

The problem still exists in version 0.17.12 and affects published ports. Each time the getStateForCache() method is executed, it may return a different order of published ports and this difference invalidates the cache.

An example of the difference in my case:

Publishers:[[URL:::, TargetPort:8000, PublishedPort:32777, Protocol:tcp], [URL:0.0.0.0, TargetPort:8000, PublishedPort:32777, Protocol:tcp]]

versus

Publishers:[[URL:0.0.0.0, TargetPort:8000, PublishedPort:32777, Protocol:tcp], [URL:::, TargetPort:8000, PublishedPort:32777, Protocol:tcp]]

As you can see, in the first case IPv6 appeared first, and in the second case it is IPv4.

[piotrminkina]

My implementation for solving this problem in PR #470.