niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #180
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestFilterOversizedClosures8=== PAUSE TestFilterOversizedClosures9=== RUN TestPartSizeForNAR10=== PAUSE TestPartSizeForNAR11=== RUN TestUploadMultipart_SupersededByPeer12=== PAUSE TestUploadMultipart_SupersededByPeer13=== RUN TestDumpPathMatchesNix14=== PAUSE TestDumpPathMatchesNix15=== RUN TestDumpPathSingleFile16=== PAUSE TestDumpPathSingleFile17=== RUN TestDumpPathWriterError18=== PAUSE TestDumpPathWriterError19=== RUN TestEncodeNixBase3220=== PAUSE TestEncodeNixBase3221=== RUN TestEncodeNixBase32WithRealHash22=== PAUSE TestEncodeNixBase32WithRealHash23=== RUN TestConvertHashToNix3224=== PAUSE TestConvertHashToNix3225=== RUN TestGetStorePathHash26=== PAUSE TestGetStorePathHash27=== RUN TestPathInfoHashCompatibility28=== PAUSE TestPathInfoHashCompatibility29=== RUN TestParsePathInfoJSON30=== PAUSE TestParsePathInfoJSON31=== RUN TestParsePathInfoJSONMultiplePaths32=== PAUSE TestParsePathInfoJSONMultiplePaths33=== RUN TestPathInfoCACompatibility34=== PAUSE TestPathInfoCACompatibility35=== RUN TestRateLimiterFeedback36=== PAUSE TestRateLimiterFeedback37=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess39=== RUN TestResolveStorePath40=== PAUSE TestResolveStorePath41=== RUN TestDoWithRetry_BodyReplayedViaGetBody42=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody43=== RUN TestShellSplit44=== PAUSE TestShellSplit45=== RUN TestShellSplitErrors46=== PAUSE TestShellSplitErrors47=== RUN TestSetClientTLS48=== PAUSE TestSetClientTLS49=== RUN TestSetClientTLSDoesNotMutateDefaultTransport50=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport51=== RUN TestSetClientTLSErrors52=== PAUSE TestSetClientTLSErrors53=== RUN TestStaticToken54=== PAUSE TestStaticToken55=== RUN TestFileTokenReadsAndCaches56=== PAUSE TestFileTokenReadsAndCaches57=== RUN TestFileTokenMissing58=== PAUSE TestFileTokenMissing59=== RUN TestFileTokenEmpty60=== PAUSE TestFileTokenEmpty61=== RUN TestScriptTokenNoExpiryRerunsEveryCall62=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall63=== RUN TestScriptTokenCachesUntilRefresh64=== PAUSE TestScriptTokenCachesUntilRefresh65=== RUN TestScriptTokenEmptyToken66=== PAUSE TestScriptTokenEmptyToken67=== RUN TestScriptTokenBadJSON68=== PAUSE TestScriptTokenBadJSON69=== RUN TestScriptTokenScriptFails70=== PAUSE TestScriptTokenScriptFails71=== RUN TestScriptTokenEmptyCommand72=== PAUSE TestScriptTokenEmptyCommand73=== CONT TestDoServerRequestAttachesToken74=== CONT TestFileTokenEmpty75=== CONT TestShellSplitErrors76=== CONT TestSetClientTLSErrors77=== CONT TestSetClientTLSDoesNotMutateDefaultTransport78=== CONT TestSetClientTLS79=== CONT TestScriptTokenBadJSON80=== CONT TestScriptTokenEmptyCommand81=== CONT TestScriptTokenEmptyToken82=== CONT TestScriptTokenScriptFails83=== CONT TestFileTokenMissing84=== CONT TestScriptTokenNoExpiryRerunsEveryCall85=== CONT TestGetStorePathHash86=== RUN TestGetStorePathHash/valid_store_path87=== CONT TestShellSplit88=== CONT TestDoWithRetry_BodyReplayedViaGetBody89=== CONT TestResolveStorePath90=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess91=== CONT TestRateLimiterFeedback92=== CONT TestPathInfoCACompatibility93=== CONT TestParsePathInfoJSONMultiplePaths94=== CONT TestParsePathInfoJSON95=== CONT TestPathInfoHashCompatibility96=== CONT TestDumpPathSingleFile97=== CONT TestConvertHashToNix3298=== CONT TestEncodeNixBase32WithRealHash99=== CONT TestEncodeNixBase32100--- PASS: TestShellSplitErrors (0.00s)101=== CONT TestDumpPathWriterError102=== CONT TestScriptTokenCachesUntilRefresh103=== PAUSE TestGetStorePathHash/valid_store_path104=== RUN TestRateLimiterFeedback/429_enables_limiter105=== CONT TestPartSizeForNAR106=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths107=== RUN TestPartSizeForNAR/zero_stays_at_minimum108--- PASS: TestFileTokenEmpty (0.00s)109--- PASS: TestScriptTokenEmptyCommand (0.00s)110=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum111=== RUN TestPartSizeForNAR/small_stays_at_minimum112=== PAUSE TestPartSizeForNAR/small_stays_at_minimum113=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum114=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum115=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts116=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts117=== RUN TestPartSizeForNAR/1_TiB1182026/09/07 10:03:41 WARN Rate limiter enabled after throttle name=server-test rate=5119=== PAUSE TestPartSizeForNAR/1_TiB120=== RUN TestPartSizeForNAR/5_TiB_S3_max_object121=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object122=== RUN TestPartSizeForNAR/capped_at_5_GiB123=== PAUSE TestPartSizeForNAR/capped_at_5_GiB124=== PAUSE TestRateLimiterFeedback/429_enables_limiter125=== RUN TestRateLimiterFeedback/503_enables_limiter126=== PAUSE TestRateLimiterFeedback/503_enables_limiter127=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter128=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter129=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter130=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter131=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths132=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths133=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths134--- PASS: TestFileTokenMissing (0.00s)135=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)136=== CONT TestDumpPathMatchesNix137=== RUN TestParsePathInfoJSON/Nix_format138=== RUN TestEncodeNixBase32/test_string_hash139--- PASS: TestShellSplit (0.00s)140=== CONT TestFilterOversizedClosures1412026/09/07 10:03:41 WARN Rate limiter enabled after throttle name=server-test rate=51422026/09/07 10:03:41 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35027143=== RUN TestGetStorePathHash/basename_without_hyphen_should_error1442026/09/07 10:03:41 WARN Rate limiter backed off name=server-test rate=5145=== CONT TestFileTokenReadsAndCaches1462026/09/07 10:03:41 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35027147=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths148=== RUN TestConvertHashToNix32/SRI_format_to_Nix32149=== CONT TestUploadMultipart_SupersededByPeer150--- PASS: TestEncodeNixBase32WithRealHash (0.00s)151=== CONT TestPartSizeForNAR/zero_stays_at_minimum152=== RUN TestUploadMultipart_SupersededByPeer/exists153--- PASS: TestResolveStorePath (0.00s)154=== CONT TestCaseHackSuffix155=== RUN TestPathInfoCACompatibility/null_ca_field156=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)157=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon158=== CONT TestPartSizeForNAR/capped_at_5_GiB159=== RUN TestSetClientTLSErrors/missing_cert_file160=== PAUSE TestParsePathInfoJSON/Nix_format161=== PAUSE TestEncodeNixBase32/test_string_hash162=== CONT TestRateLimiterFeedback/429_enables_limiter163=== RUN TestFilterOversizedClosures/no_limit_keeps_everything164=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error165=== PAUSE TestUploadMultipart_SupersededByPeer/exists166=== CONT TestStaticToken167=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter168=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32169--- PASS: TestScriptTokenScriptFails (0.00s)170=== PAUSE TestPathInfoCACompatibility/null_ca_field171=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter172=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon173--- PASS: TestScriptTokenBadJSON (0.00s)174=== PAUSE TestSetClientTLSErrors/missing_cert_file175=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths176=== CONT TestPartSizeForNAR/5_TiB_S3_max_object177=== RUN TestEncodeNixBase32/empty_input178=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything179=== RUN TestParsePathInfoJSON/Lix_format180=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts181=== RUN TestSetClientTLS/rejects_connection_without_client_cert182=== CONT TestPartSizeForNAR/1_TiB183=== CONT TestRateLimiterFeedback/503_enables_limiter184--- PASS: TestScriptTokenEmptyToken (0.00s)185=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum186=== RUN TestPathInfoCACompatibility/old_string_format_-_text187=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert188--- PASS: TestDoServerRequestAttachesToken (0.01s)189=== PAUSE TestEncodeNixBase32/empty_input1902026/09/07 10:03:41 WARN Rate limiter enabled after throttle name=server-test rate=51912026/09/07 10:03:41 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:358531922026/09/07 10:03:41 WARN Rate limiter enabled after throttle name=server-test rate=51932026/09/07 10:03:41 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:465051942026/09/07 10:03:41 WARN Rate limiter backed off name=server-test rate=51952026/09/07 10:03:41 WARN Rate limiter backed off name=server-test rate=5196=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI197=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI198=== CONT TestEncodeNixBase32/empty_input199=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512200=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512201=== RUN TestConvertHashToNix32/already_Nix32_format202=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error203=== RUN TestUploadMultipart_SupersededByPeer/missing204=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped205=== PAUSE TestConvertHashToNix32/already_Nix32_format206=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped207=== PAUSE TestUploadMultipart_SupersededByPeer/missing208=== PAUSE TestParsePathInfoJSON/Lix_format209=== CONT TestPartSizeForNAR/small_stays_at_minimum210=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text211--- PASS: TestFileTokenReadsAndCaches (0.00s)212=== RUN TestSetClientTLSErrors/missing_key_file213=== CONT TestEncodeNixBase32/test_string_hash214--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)215=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512216=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI217=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon218=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error219=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA220=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA221=== RUN TestSetClientTLS/preserves_debug_logging_transport222=== RUN TestConvertHashToNix32/invalid_format223=== RUN TestFilterOversizedClosures/all_closures_skipped224=== CONT TestUploadMultipart_SupersededByPeer/exists225=== CONT TestUploadMultipart_SupersededByPeer/missing226=== RUN TestParsePathInfoJSON/empty_input227=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive228=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)229--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)230=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error231=== PAUSE TestSetClientTLSErrors/missing_key_file232=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error233=== CONT TestGetStorePathHash/valid_store_path234=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error235=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive236=== RUN TestPathInfoCACompatibility/new_structured_format_-_text237=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text238=== PAUSE TestFilterOversizedClosures/all_closures_skipped239=== CONT TestFilterOversizedClosures/no_limit_keeps_everything240=== CONT TestFilterOversizedClosures/all_closures_skipped241=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method242=== PAUSE TestConvertHashToNix32/invalid_format2432026/09/07 10:03:41 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50244=== PAUSE TestSetClientTLS/preserves_debug_logging_transport245=== CONT TestSetClientTLS/rejects_connection_without_client_cert246=== CONT TestSetClientTLS/preserves_debug_logging_transport247=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA248=== PAUSE TestParsePathInfoJSON/empty_input249=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error250=== CONT TestGetStorePathHash/basename_without_hyphen_should_error251--- PASS: TestStaticToken (0.00s)252=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2532026/09/07 10:03:41 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000254=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method255=== CONT TestConvertHashToNix32/SRI_format_to_Nix32256=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method257=== CONT TestConvertHashToNix32/invalid_format258=== CONT TestConvertHashToNix32/already_Nix32_format259=== RUN TestSetClientTLSErrors/missing_ca_file260=== PAUSE TestSetClientTLSErrors/missing_ca_file261=== RUN TestParsePathInfoJSON/whitespace_only262--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)263 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)264 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)265--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)266--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)267=== CONT TestPathInfoCACompatibility/null_ca_field268=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive269=== CONT TestPathInfoCACompatibility/new_structured_format_-_text270=== CONT TestPathInfoCACompatibility/old_string_format_-_text271=== RUN TestSetClientTLSErrors/invalid_ca_file272=== PAUSE TestParsePathInfoJSON/whitespace_only273=== RUN TestParsePathInfoJSON/invalid_JSON274--- PASS: TestDumpPathSingleFile (0.04s)275--- PASS: TestGetStorePathHash (0.04s)276 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)277 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)278 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)279 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)280=== PAUSE TestSetClientTLSErrors/invalid_ca_file281=== CONT TestSetClientTLSErrors/missing_cert_file282=== CONT TestSetClientTLSErrors/invalid_ca_file283=== PAUSE TestParsePathInfoJSON/invalid_JSON284--- PASS: TestConvertHashToNix32 (0.04s)285 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)286 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)287 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)288=== CONT TestSetClientTLSErrors/missing_ca_file289=== CONT TestSetClientTLSErrors/missing_key_file290=== CONT TestParsePathInfoJSON/Nix_format291=== CONT TestParsePathInfoJSON/empty_input292=== CONT TestParsePathInfoJSON/whitespace_only293=== CONT TestParsePathInfoJSON/Lix_format294=== CONT TestParsePathInfoJSON/invalid_JSON295--- PASS: TestRateLimiterFeedback (0.00s)296 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)297 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)298 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)299 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)300--- PASS: TestPartSizeForNAR (0.00s)301 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)302 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)303 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)304 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)305 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)306 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)307 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)308--- PASS: TestEncodeNixBase32 (0.01s)309 --- PASS: TestEncodeNixBase32/empty_input (0.00s)310 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)311--- PASS: TestPathInfoHashCompatibility (0.02s)312 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)313 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)314 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)315 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)316--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)317 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)318 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)319--- PASS: TestPathInfoCACompatibility (0.04s)320 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)321 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)322 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)323 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)324 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)325--- PASS: TestFilterOversizedClosures (0.03s)326 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)327 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)328 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)329--- PASS: TestParsePathInfoJSON (0.04s)330 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)331 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)332 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)333 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)334 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)335--- PASS: TestSetClientTLSErrors (0.04s)336 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)337 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)338 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)339 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)340--- PASS: TestCaseHackSuffix (0.04s)3412026/09/07 10:03:41 http: TLS handshake error from 127.0.0.1:35432: remote error: tls: bad certificate342--- PASS: TestSetClientTLS (0.04s)343 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)344 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)345 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)346--- PASS: TestDumpPathWriterError (0.07s)347--- PASS: TestDumpPathMatchesNix (0.11s)348--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)349PASS350Running server tests...351The files belonging to this database system will be owned by user "nixbld".352This user must also own the server process.353354The database cluster will be initialized with locale "C".355The default database encoding has accordingly been set to "SQL_ASCII".356The default text search configuration will be set to "english".357358Data page checksums are enabled.359360creating directory /build/postgres2875671300/data ... ok361creating subdirectories ... ok362selecting dynamic shared memory implementation ... posix363selecting default "max_connections" ... 100364selecting default "shared_buffers" ... 128MB365selecting default time zone ... UTC366creating configuration files ... ok367running bootstrap script ... ok368performing post-bootstrap initialization ... ok369syncing data to disk ... ok370371initdb: warning: enabling "trust" authentication for local connections372initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.373374Success. You can now start the database server using:375376 pg_ctl -D /build/postgres2875671300/data -l logfile start377378/build/postgres2875671300:5432 - no response3792026-09-07 10:03:43.677 UTC [110] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit3802026-09-07 10:03:43.678 UTC [110] LOG: listening on Unix socket "/build/postgres2875671300/.s.PGSQL.5432"3812026-09-07 10:03:43.683 UTC [117] LOG: database system was shut down at 2026-09-07 10:03:43 UTC3822026-09-07 10:03:43.687 UTC [110] LOG: database system is ready to accept connections383/build/postgres2875671300:5432 - accepting connections384=== RUN TestService_AuthMiddleware385=== PAUSE TestService_AuthMiddleware386=== RUN TestService_AuthMiddleware_MTLSProxyHeader387=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader388=== RUN TestService_AuthMiddleware_MTLSBoundSubjects389=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects390=== RUN TestService_ReadAuthMiddleware391=== PAUSE TestService_ReadAuthMiddleware392=== RUN TestService_AuthMiddleware_OIDC393=== PAUSE TestService_AuthMiddleware_OIDC394=== RUN TestService_RequireScope_OIDC395=== PAUSE TestService_RequireScope_OIDC396=== RUN TestService_ReadScope_PublicByDefault397=== PAUSE TestService_ReadScope_PublicByDefault398=== RUN TestCacheConfigHandler399=== PAUSE TestCacheConfigHandler400=== RUN TestCacheStatsHandler401=== PAUSE TestCacheStatsHandler402=== RUN TestClaim_BuildWaitComplete403=== PAUSE TestClaim_BuildWaitComplete404=== RUN TestClaim_GCMarkedOutputCountsAsAbsent405=== PAUSE TestClaim_GCMarkedOutputCountsAsAbsent406=== RUN TestClaim_TooManyStreams407=== PAUSE TestClaim_TooManyStreams408=== RUN TestClaim_HolderDisconnectKeepsClaim409=== PAUSE TestClaim_HolderDisconnectKeepsClaim410=== RUN TestClaim_FailWakesWaitersButIsNotRemembered411=== PAUSE TestClaim_FailWakesWaitersButIsNotRemembered412=== RUN TestClaim_FailWithoutKindReleases413=== PAUSE TestClaim_FailWithoutKindReleases414=== RUN TestClaim_StaleHeartbeatStolen415=== PAUSE TestClaim_StaleHeartbeatStolen416=== RUN TestClaim_TwoInstances417=== PAUSE TestClaim_TwoInstances418=== RUN TestClaim_InputsTouched419=== PAUSE TestClaim_InputsTouched420=== RUN TestClaim_StreamsThroughServer421=== PAUSE TestClaim_StreamsThroughServer422=== RUN TestClientCADerivations423=== PAUSE TestClientCADerivations424=== RUN TestClientErrorHandling425=== PAUSE TestClientErrorHandling426=== RUN TestClientIntegration427=== PAUSE TestClientIntegration428=== RUN TestClientMultipleUploads429=== PAUSE TestClientMultipleUploads430=== RUN TestClientWithDependencies431=== PAUSE TestClientWithDependencies432=== RUN TestPinProtectsFromGC433=== PAUSE TestPinProtectsFromGC434=== RUN TestResolveDBConnectionString435=== PAUSE TestResolveDBConnectionString436=== RUN TestGCAdvisoryLockBlocksConcurrentRun4372026-09-07 10:03:47.970 UTC [522] ERROR: relation "goose_db_version" does not exist at character 364382026-09-07 10:03:47.970 UTC [522] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4392026/09/07 10:03:47 OK 20241026095416_initial_model.sql (13.92ms)4402026/09/07 10:03:47 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)4412026/09/07 10:03:47 OK 20251218171726_add_pins.sql (3.66ms)4422026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (3.3ms)4432026/09/07 10:03:48 OK 20260905000000_add_claims.sql (3.65ms)4442026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000004452026/09/07 10:03:48 OK 1_commit_pending_closure.sql (2.04ms)4462026/09/07 10:03:48 OK 2_object_stats_trigger.sql (980.41µs)4472026/09/07 10:03:48 goose: up to current file version: 2448--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.36s)449=== RUN TestGCBugBareHashReferences450=== PAUSE TestGCBugBareHashReferences451=== RUN TestGCMetrics452=== PAUSE TestGCMetrics453=== RUN TestGCTaskStore_StartNew454=== PAUSE TestGCTaskStore_StartNew455=== RUN TestGCTaskStore_DeduplicateSameParams456=== PAUSE TestGCTaskStore_DeduplicateSameParams457=== RUN TestGCTaskStore_ConflictDifferentParams458=== PAUSE TestGCTaskStore_ConflictDifferentParams459=== RUN TestGCTaskStore_GetEmpty460=== PAUSE TestGCTaskStore_GetEmpty461=== RUN TestGCTaskStore_GetReturnsLatest462=== PAUSE TestGCTaskStore_GetReturnsLatest463=== RUN TestGCTaskStore_CompletedAllowsNewTask464=== PAUSE TestGCTaskStore_CompletedAllowsNewTask465=== RUN TestGCTaskStore_PhaseUpdates466=== PAUSE TestGCTaskStore_PhaseUpdates467=== RUN TestGCTaskStore_Fail468=== PAUSE TestGCTaskStore_Fail469=== RUN TestGracefulShutdownDrainsInflight470=== PAUSE TestGracefulShutdownDrainsInflight471=== RUN TestService_healthCheckHandler472=== PAUSE TestService_healthCheckHandler473=== RUN TestService_readinessHandler474=== PAUSE TestService_readinessHandler475=== RUN TestGenerateLandingPage476=== PAUSE TestGenerateLandingPage477=== RUN TestCacheConfigHandlerMaxNarSize478=== PAUSE TestCacheConfigHandlerMaxNarSize479=== RUN TestCreatePendingClosureRejectsOversizedNAR480=== PAUSE TestCreatePendingClosureRejectsOversizedNAR481=== RUN TestNARDeduplicationMetadataUploadBug482=== PAUSE TestNARDeduplicationMetadataUploadBug483=== RUN TestMetricsInventory484=== PAUSE TestMetricsInventory485=== RUN TestService_NativeMTLS486=== PAUSE TestService_NativeMTLS487=== RUN TestServerTLSConfig488=== PAUSE TestServerTLSConfig489=== RUN TestMultipartCleanup490=== PAUSE TestMultipartCleanup491=== RUN TestObjectStatsTrigger492=== PAUSE TestObjectStatsTrigger493=== RUN TestOrphanedObjectsGC494=== PAUSE TestOrphanedObjectsGC495=== RUN TestOrphanedObjectsGCStressTest496=== PAUSE TestOrphanedObjectsGCStressTest497=== RUN TestResurrectedObjectNotDeleted498=== PAUSE TestResurrectedObjectNotDeleted499=== RUN TestParseSingleRange500=== PAUSE TestParseSingleRange501=== RUN TestIsValidCachePath502=== PAUSE TestIsValidCachePath503=== RUN TestReadProxyNarinfo504=== PAUSE TestReadProxyNarinfo505=== RUN TestReadProxyNarinfoAlreadyDecompressed506=== PAUSE TestReadProxyNarinfoAlreadyDecompressed507=== RUN TestReadProxyNarStreaming508=== PAUSE TestReadProxyNarStreaming509=== RUN TestReadProxy404510=== PAUSE TestReadProxy404511=== RUN TestReadProxyInvalidPath512=== PAUSE TestReadProxyInvalidPath513=== RUN TestReadProxyHead514=== PAUSE TestReadProxyHead515=== RUN TestReadProxyConditionalGet516=== PAUSE TestReadProxyConditionalGet517=== RUN TestReadProxyRootRedirectsToIndexHTML518=== PAUSE TestReadProxyRootRedirectsToIndexHTML519=== RUN TestReadProxyDisabled520=== PAUSE TestReadProxyDisabled521=== RUN TestReadRedirectNar522=== PAUSE TestReadRedirectNar523=== RUN TestReadRedirectKeepsNarinfoProxied524=== PAUSE TestReadRedirectKeepsNarinfoProxied525=== RUN TestReadProxyRangeRequest526=== PAUSE TestReadProxyRangeRequest527=== RUN TestReadRedirectUsesPublicS3URL528=== PAUSE TestReadRedirectUsesPublicS3URL529=== RUN TestRedundantMultipartUpload530=== PAUSE TestRedundantMultipartUpload531=== RUN TestCompleteMultipartUpload_ErrorButObjectExists532=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists533=== RUN TestCompletedNarNotReofferedAcrossClosures534=== PAUSE TestCompletedNarNotReofferedAcrossClosures535=== RUN TestPresignedUploadRegisteredBeforeCommit536=== PAUSE TestPresignedUploadRegisteredBeforeCommit537=== RUN TestService_Rustfstest538=== PAUSE TestService_Rustfstest539=== RUN TestParseSize540=== PAUSE TestParseSize541=== RUN TestSkippedUploadsHandler542=== PAUSE TestSkippedUploadsHandler543=== RUN TestSystemdListenerNotActivated544--- PASS: TestSystemdListenerNotActivated (0.00s)545=== RUN TestWatchdogBeatsWhenHealthy546--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)547=== RUN TestWatchdogSkipsWhenUnhealthy5482026/09/07 10:03:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5492026/09/07 10:03:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5502026/09/07 10:03:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5512026/09/07 10:03:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5522026/09/07 10:03:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5532026/09/07 10:03:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5542026/09/07 10:03:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5552026/09/07 10:03:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5562026/09/07 10:03:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5572026/09/07 10:03:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"558--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)559=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle560=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle561=== RUN TestProxyWriteTimeout562=== PAUSE TestProxyWriteTimeout563=== RUN TestIsValidUploadKey564=== PAUSE TestIsValidUploadKey565=== RUN TestUploadHandlersRejectInvalidKeys566=== PAUSE TestUploadHandlersRejectInvalidKeys567=== RUN TestUploadHandlersRejectOversizedBody568=== PAUSE TestUploadHandlersRejectOversizedBody569=== RUN TestService_cleanupPendingClosuresHandler570=== PAUSE TestService_cleanupPendingClosuresHandler571=== RUN TestService_createPendingClosureHandler572=== PAUSE TestService_createPendingClosureHandler573=== RUN TestService_verifyS3Integrity574=== PAUSE TestService_verifyS3Integrity575=== RUN TestCompleteMultipartUnregistered576=== PAUSE TestCompleteMultipartUnregistered577=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT578=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT579=== CONT TestParseSize580=== CONT TestGCTaskStore_GetEmpty581=== CONT TestRedundantMultipartUpload582=== CONT TestService_AuthMiddleware583=== CONT TestGCTaskStore_Fail584--- PASS: TestGCTaskStore_GetEmpty (0.00s)585--- PASS: TestGCTaskStore_Fail (0.00s)586=== CONT TestService_Rustfstest587=== CONT TestPresignedUploadRegisteredBeforeCommit588=== CONT TestGCTaskStore_PhaseUpdates589--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)590=== CONT TestGCTaskStore_CompletedAllowsNewTask591=== CONT TestGCTaskStore_GetReturnsLatest592=== CONT TestCompletedNarNotReofferedAcrossClosures593=== CONT TestCompleteMultipartUpload_ErrorButObjectExists594=== CONT TestGCTaskStore_ConflictDifferentParams595=== CONT TestGCTaskStore_DeduplicateSameParams596=== CONT TestGCTaskStore_StartNew597=== CONT TestGCMetrics598=== CONT TestGCBugBareHashReferences599=== CONT TestResolveDBConnectionString600=== CONT TestPinProtectsFromGC601=== CONT TestClientWithDependencies602=== CONT TestClientMultipleUploads603=== CONT TestClientIntegration604=== CONT TestClientErrorHandling605=== CONT TestClientCADerivations606=== CONT TestUploadHandlersRejectOversizedBody607=== CONT TestClaim_StreamsThroughServer608--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)609--- PASS: TestParseSize (0.00s)610=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT611=== CONT TestClaim_StaleHeartbeatStolen612=== CONT TestCompleteMultipartUnregistered613=== CONT TestService_verifyS3Integrity614=== CONT TestClaim_FailWithoutKindReleases615=== CONT TestClaim_TwoInstances616=== RUN TestResolveDBConnectionString/flag_wins617=== PAUSE TestResolveDBConnectionString/flag_wins618=== RUN TestResolveDBConnectionString/file_when_flag_empty619=== PAUSE TestResolveDBConnectionString/file_when_flag_empty620=== RUN TestResolveDBConnectionString/missing_file_is_an_error621=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error622=== RUN TestResolveDBConnectionString/PGHOST_allows_empty623=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty624=== RUN TestResolveDBConnectionString/nothing_configured625=== PAUSE TestResolveDBConnectionString/nothing_configured626=== CONT TestService_createPendingClosureHandler627--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)628=== RUN TestClientErrorHandling/InvalidStorePath629=== CONT TestClaim_InputsTouched630--- PASS: TestGCTaskStore_StartNew (0.00s)631--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)632--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)633=== PAUSE TestClientErrorHandling/InvalidStorePath634=== RUN TestClientErrorHandling/InvalidAuthToken635=== PAUSE TestClientErrorHandling/InvalidAuthToken636=== RUN TestClientErrorHandling/ServerNotAvailable637=== PAUSE TestClientErrorHandling/ServerNotAvailable638=== CONT TestClaim_FailWakesWaitersButIsNotRemembered6392026-09-07 10:03:48.536 UTC [605] ERROR: relation "goose_db_version" does not exist at character 366402026-09-07 10:03:48.536 UTC [605] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6412026-09-07 10:03:48.549 UTC [606] ERROR: relation "goose_db_version" does not exist at character 366422026-09-07 10:03:48.549 UTC [606] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6432026-09-07 10:03:48.566 UTC [607] ERROR: relation "goose_db_version" does not exist at character 366442026-09-07 10:03:48.566 UTC [607] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6452026-09-07 10:03:48.596 UTC [608] ERROR: relation "goose_db_version" does not exist at character 366462026-09-07 10:03:48.596 UTC [608] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6472026-09-07 10:03:48.599 UTC [609] ERROR: relation "goose_db_version" does not exist at character 366482026-09-07 10:03:48.599 UTC [609] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC649=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure650=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure651=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart652=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart653=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts654=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts655=== CONT TestService_cleanupPendingClosuresHandler6562026/09/07 10:03:48 OK 20241026095416_initial_model.sql (68.33ms)6572026-09-07 10:03:48.633 UTC [612] ERROR: relation "goose_db_version" does not exist at character 366582026-09-07 10:03:48.633 UTC [612] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6592026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (23.29ms)6602026/09/07 10:03:48 OK 20241026095416_initial_model.sql (97.03ms)6612026/09/07 10:03:48 OK 20251218171726_add_pins.sql (24.01ms)6622026/09/07 10:03:48 OK 20241026095416_initial_model.sql (88.61ms)6632026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (7.1ms)6642026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (4.24ms)6652026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (11.26ms)6662026-09-07 10:03:48.693 UTC [613] ERROR: relation "goose_db_version" does not exist at character 366672026-09-07 10:03:48.693 UTC [613] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6682026-09-07 10:03:48.696 UTC [614] ERROR: relation "goose_db_version" does not exist at character 366692026-09-07 10:03:48.696 UTC [614] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6702026-09-07 10:03:48.696 UTC [615] ERROR: relation "goose_db_version" does not exist at character 366712026-09-07 10:03:48.696 UTC [615] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6722026/09/07 10:03:48 OK 20241026095416_initial_model.sql (35.46ms)6732026/09/07 10:03:48 OK 20251218171726_add_pins.sql (11.4ms)6742026/09/07 10:03:48 OK 20251218171726_add_pins.sql (11.27ms)6752026/09/07 10:03:48 OK 20260905000000_add_claims.sql (10.93ms)6762026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000006772026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (6.11ms)6782026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (20.23ms)6792026/09/07 10:03:48 OK 20241026095416_initial_model.sql (37.27ms)6802026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (17.69ms)6812026/09/07 10:03:48 OK 1_commit_pending_closure.sql (16.19ms)6822026/09/07 10:03:48 OK 2_object_stats_trigger.sql (3.46ms)6832026/09/07 10:03:48 goose: up to current file version: 26842026/09/07 10:03:48 OK 20251218171726_add_pins.sql (22.58ms)6852026/09/07 10:03:48 OK 20241026095416_initial_model.sql (42.66ms)6862026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (6.5ms)6872026/09/07 10:03:48 OK 20260905000000_add_claims.sql (7.69ms)6882026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000006892026/09/07 10:03:48 OK 20260905000000_add_claims.sql (8.62ms)6902026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000006912026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (6.12ms)6922026/09/07 10:03:48 OK 1_commit_pending_closure.sql (5.6ms)6932026/09/07 10:03:48 OK 1_commit_pending_closure.sql (7.74ms)6942026/09/07 10:03:48 OK 20251218171726_add_pins.sql (9.51ms)6952026/09/07 10:03:48 OK 2_object_stats_trigger.sql (4.8ms)6962026/09/07 10:03:48 goose: up to current file version: 26972026/09/07 10:03:48 OK 20241026095416_initial_model.sql (27.33ms)6982026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (12.69ms)6992026/09/07 10:03:48 OK 20241026095416_initial_model.sql (21.63ms)7002026-09-07 10:03:48.745 UTC [617] ERROR: relation "goose_db_version" does not exist at character 367012026-09-07 10:03:48.745 UTC [617] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7022026-09-07 10:03:48.745 UTC [620] ERROR: relation "goose_db_version" does not exist at character 367032026-09-07 10:03:48.745 UTC [620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7042026/09/07 10:03:48 OK 2_object_stats_trigger.sql (9.42ms)7052026/09/07 10:03:48 OK 20241026095416_initial_model.sql (24.15ms)7062026/09/07 10:03:48 goose: up to current file version: 27072026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (7.12ms)7082026-09-07 10:03:48.746 UTC [616] ERROR: relation "goose_db_version" does not exist at character 367092026-09-07 10:03:48.746 UTC [616] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7102026/09/07 10:03:48 OK 20251218171726_add_pins.sql (13.31ms)7112026-09-07 10:03:48.747 UTC [618] ERROR: relation "goose_db_version" does not exist at character 367122026-09-07 10:03:48.747 UTC [618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7132026-09-07 10:03:48.748 UTC [619] ERROR: relation "goose_db_version" does not exist at character 367142026-09-07 10:03:48.748 UTC [619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7152026-09-07 10:03:48.749 UTC [621] ERROR: relation "goose_db_version" does not exist at character 367162026-09-07 10:03:48.749 UTC [621] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7172026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (14.58ms)7182026/09/07 10:03:48 OK 20260905000000_add_claims.sql (11.9ms)7192026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000007202026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (11ms)7212026-09-07 10:03:48.758 UTC [622] ERROR: relation "goose_db_version" does not exist at character 367222026-09-07 10:03:48.758 UTC [622] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7232026/09/07 10:03:48 OK 1_commit_pending_closure.sql (14.77ms)7242026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (19.97ms)7252026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (20.17ms)7262026/09/07 10:03:48 OK 20260905000000_add_claims.sql (17.58ms)7272026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000007282026/09/07 10:03:48 OK 20251218171726_add_pins.sql (22.73ms)7292026/09/07 10:03:48 OK 20251218171726_add_pins.sql (13.23ms)7302026/09/07 10:03:48 OK 2_object_stats_trigger.sql (3.8ms)7312026/09/07 10:03:48 goose: up to current file version: 27322026/09/07 10:03:48 OK 20260905000000_add_claims.sql (4.94ms)7332026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000007342026/09/07 10:03:48 OK 20251218171726_add_pins.sql (9.62ms)7352026/09/07 10:03:48 OK 1_commit_pending_closure.sql (9.36ms)7362026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (10.96ms)7372026/09/07 10:03:48 OK 1_commit_pending_closure.sql (8.53ms)7382026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (11.08ms)7392026/09/07 10:03:48 OK 2_object_stats_trigger.sql (2.77ms)7402026/09/07 10:03:48 goose: up to current file version: 27412026/09/07 10:03:48 OK 20241026095416_initial_model.sql (14.23ms)7422026-09-07 10:03:48.785 UTC [623] ERROR: relation "goose_db_version" does not exist at character 367432026-09-07 10:03:48.785 UTC [623] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7442026/09/07 10:03:48 OK 2_object_stats_trigger.sql (4.96ms)7452026-09-07 10:03:48.785 UTC [625] ERROR: relation "goose_db_version" does not exist at character 367462026-09-07 10:03:48.785 UTC [625] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7472026/09/07 10:03:48 goose: up to current file version: 27482026/09/07 10:03:48 OK 20241026095416_initial_model.sql (17.51ms)7492026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (9.47ms)7502026-09-07 10:03:48.786 UTC [624] ERROR: relation "goose_db_version" does not exist at character 367512026-09-07 10:03:48.786 UTC [624] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7522026-09-07 10:03:48.788 UTC [627] ERROR: relation "goose_db_version" does not exist at character 367532026-09-07 10:03:48.788 UTC [627] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7542026/09/07 10:03:48 OK 20260905000000_add_claims.sql (8.89ms)7552026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000007562026-09-07 10:03:48.792 UTC [626] ERROR: relation "goose_db_version" does not exist at character 367572026-09-07 10:03:48.792 UTC [626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7582026/09/07 10:03:48 OK 20260905000000_add_claims.sql (12.17ms)7592026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000007602026/09/07 10:03:48 OK 1_commit_pending_closure.sql (4.33ms)7612026/09/07 10:03:48 OK 20241026095416_initial_model.sql (17.23ms)7622026/09/07 10:03:48 OK 20241026095416_initial_model.sql (17.19ms)7632026/09/07 10:03:48 OK 20241026095416_initial_model.sql (21.18ms)7642026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (9.61ms)7652026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (8.47ms)7662026-09-07 10:03:48.794 UTC [628] ERROR: relation "goose_db_version" does not exist at character 367672026-09-07 10:03:48.794 UTC [628] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7682026-09-07 10:03:48.794 UTC [629] ERROR: relation "goose_db_version" does not exist at character 367692026-09-07 10:03:48.794 UTC [629] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7702026/09/07 10:03:48 OK 20241026095416_initial_model.sql (23.68ms)7712026/09/07 10:03:48 OK 20260905000000_add_claims.sql (8.97ms)7722026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000007732026/09/07 10:03:48 OK 20241026095416_initial_model.sql (17.07ms)7742026/09/07 10:03:48 OK 2_object_stats_trigger.sql (2.07ms)7752026/09/07 10:03:48 goose: up to current file version: 27762026/09/07 10:03:48 OK 20251218171726_add_pins.sql (3.43ms)7772026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)7782026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (3.44ms)7792026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (3.52ms)7802026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (3.55ms)7812026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)7822026/09/07 10:03:48 OK 1_commit_pending_closure.sql (7.94ms)7832026/09/07 10:03:48 OK 20251218171726_add_pins.sql (8.86ms)7842026/09/07 10:03:48 OK 1_commit_pending_closure.sql (8.36ms)7852026/09/07 10:03:48 OK 20251218171726_add_pins.sql (6.27ms)7862026/09/07 10:03:48 OK 20251218171726_add_pins.sql (6.3ms)7872026/09/07 10:03:48 OK 20251218171726_add_pins.sql (6.51ms)7882026/09/07 10:03:48 OK 20251218171726_add_pins.sql (6.54ms)7892026/09/07 10:03:48 OK 2_object_stats_trigger.sql (3.42ms)7902026/09/07 10:03:48 goose: up to current file version: 27912026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (8.39ms)7922026/09/07 10:03:48 OK 20251218171726_add_pins.sql (7.62ms)7932026/09/07 10:03:48 OK 2_object_stats_trigger.sql (3.98ms)7942026/09/07 10:03:48 goose: up to current file version: 27952026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (6.88ms)7962026-09-07 10:03:48.812 UTC [630] ERROR: relation "goose_db_version" does not exist at character 367972026-09-07 10:03:48.812 UTC [630] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7982026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (10.05ms)7992026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (8.56ms)8002026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (10.24ms)8012026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (8.7ms)8022026/09/07 10:03:48 OK 20260905000000_add_claims.sql (8.77ms)8032026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008042026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (10.12ms)8052026/09/07 10:03:48 OK 20241026095416_initial_model.sql (19.24ms)8062026/09/07 10:03:48 OK 20241026095416_initial_model.sql (18.46ms)8072026/09/07 10:03:48 OK 20260905000000_add_claims.sql (5.69ms)8082026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008092026/09/07 10:03:48 OK 20241026095416_initial_model.sql (19.91ms)8102026/09/07 10:03:48 OK 20241026095416_initial_model.sql (19.14ms)8112026/09/07 10:03:48 OK 20260905000000_add_claims.sql (5.61ms)8122026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008132026/09/07 10:03:48 OK 20260905000000_add_claims.sql (5.74ms)8142026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008152026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (3.67ms)8162026/09/07 10:03:48 OK 1_commit_pending_closure.sql (4.95ms)8172026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (3.64ms)8182026/09/07 10:03:48 OK 20260905000000_add_claims.sql (5.16ms)8192026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008202026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (3ms)8212026/09/07 10:03:48 OK 20260905000000_add_claims.sql (6.15ms)8222026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008232026/09/07 10:03:48 OK 20260905000000_add_claims.sql (6.34ms)8242026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008252026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (3.52ms)8262026/09/07 10:03:48 OK 1_commit_pending_closure.sql (5.35ms)8272026/09/07 10:03:48 OK 20241026095416_initial_model.sql (13.03ms)8282026/09/07 10:03:48 OK 1_commit_pending_closure.sql (3.65ms)8292026/09/07 10:03:48 OK 2_object_stats_trigger.sql (3.46ms)8302026/09/07 10:03:48 OK 1_commit_pending_closure.sql (4.52ms)8312026/09/07 10:03:48 goose: up to current file version: 28322026/09/07 10:03:48 OK 20251218171726_add_pins.sql (4.91ms)8332026/09/07 10:03:48 OK 20241026095416_initial_model.sql (15.84ms)8342026/09/07 10:03:48 OK 1_commit_pending_closure.sql (4.68ms)8352026/09/07 10:03:48 OK 1_commit_pending_closure.sql (4.08ms)8362026/09/07 10:03:48 OK 2_object_stats_trigger.sql (2.8ms)8372026/09/07 10:03:48 goose: up to current file version: 28382026/09/07 10:03:48 OK 20251218171726_add_pins.sql (5.43ms)8392026/09/07 10:03:48 OK 2_object_stats_trigger.sql (2.98ms)8402026/09/07 10:03:48 goose: up to current file version: 28412026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (3.19ms)8422026/09/07 10:03:48 OK 20251218171726_add_pins.sql (5.22ms)8432026/09/07 10:03:48 OK 1_commit_pending_closure.sql (4.22ms)8442026/09/07 10:03:48 OK 20251218171726_add_pins.sql (4.57ms)8452026/09/07 10:03:48 OK 2_object_stats_trigger.sql (1.91ms)8462026/09/07 10:03:48 goose: up to current file version: 28472026/09/07 10:03:48 OK 2_object_stats_trigger.sql (2.91ms)8482026/09/07 10:03:48 goose: up to current file version: 28492026/09/07 10:03:48 OK 2_object_stats_trigger.sql (5.03ms)8502026/09/07 10:03:48 goose: up to current file version: 28512026/09/07 10:03:48 OK 20241026095416_initial_model.sql (21.03ms)8522026/09/07 10:03:48 OK 2_object_stats_trigger.sql (4.49ms)8532026/09/07 10:03:48 goose: up to current file version: 28542026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (5.97ms)8552026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (7.88ms)8562026/09/07 10:03:48 OK 20251218171726_add_pins.sql (6.89ms)8572026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (7.01ms)8582026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (6.77ms)8592026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (7.13ms)8602026/09/07 10:03:48 OK 20241026095416_initial_model.sql (12.68ms)8612026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (2.95ms)8622026/09/07 10:03:48 OK 20251218171726_add_pins.sql (4.06ms)8632026/09/07 10:03:48 OK 20251210153512_drop_unused_gin_index.sql (3.22ms)8642026/09/07 10:03:48 OK 20260905000000_add_claims.sql (4.81ms)8652026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008662026/09/07 10:03:48 OK 20260905000000_add_claims.sql (6.5ms)8672026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008682026/09/07 10:03:48 OK 20260905000000_add_claims.sql (6.62ms)8692026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008702026/09/07 10:03:48 OK 20260905000000_add_claims.sql (6.2ms)8712026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008722026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (6.7ms)8732026/09/07 10:03:48 OK 20251218171726_add_pins.sql (6.44ms)8742026/09/07 10:03:48 OK 20251218171726_add_pins.sql (3.39ms)8752026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (5.07ms)8762026/09/07 10:03:48 OK 1_commit_pending_closure.sql (2.62ms)8772026/09/07 10:03:48 OK 1_commit_pending_closure.sql (3.16ms)8782026/09/07 10:03:48 OK 2_object_stats_trigger.sql (3.08ms)8792026/09/07 10:03:48 goose: up to current file version: 28802026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (3.69ms)8812026/09/07 10:03:48 OK 1_commit_pending_closure.sql (4.23ms)8822026/09/07 10:03:48 OK 20260905000000_add_claims.sql (4.44ms)8832026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008842026/09/07 10:03:48 OK 20260628120000_add_object_size_and_stats.sql (4.26ms)8852026/09/07 10:03:48 OK 2_object_stats_trigger.sql (2.22ms)8862026/09/07 10:03:48 goose: up to current file version: 28872026/09/07 10:03:48 OK 2_object_stats_trigger.sql (1.31ms)8882026/09/07 10:03:48 goose: up to current file version: 28892026/09/07 10:03:48 OK 20260905000000_add_claims.sql (5.37ms)8902026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008912026/09/07 10:03:48 OK 1_commit_pending_closure.sql (2.07ms)8922026/09/07 10:03:48 OK 20260905000000_add_claims.sql (3.56ms)8932026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008942026/09/07 10:03:48 OK 2_object_stats_trigger.sql (1.31ms)8952026/09/07 10:03:48 goose: up to current file version: 28962026/09/07 10:03:48 OK 20260905000000_add_claims.sql (3.57ms)8972026/09/07 10:03:48 goose: successfully migrated database to version: 202609050000008982026/09/07 10:03:48 OK 1_commit_pending_closure.sql (3.55ms)8992026/09/07 10:03:48 OK 1_commit_pending_closure.sql (2.12ms)9002026/09/07 10:03:48 OK 1_commit_pending_closure.sql (2.06ms)9012026/09/07 10:03:48 OK 2_object_stats_trigger.sql (1.51ms)9022026/09/07 10:03:48 goose: up to current file version: 29032026/09/07 10:03:48 OK 2_object_stats_trigger.sql (1.5ms)9042026/09/07 10:03:48 goose: up to current file version: 29052026/09/07 10:03:48 OK 2_object_stats_trigger.sql (1.22ms)9062026/09/07 10:03:48 goose: up to current file version: 29072026/09/07 10:03:48 OK 1_commit_pending_closure.sql (15.34ms)9082026/09/07 10:03:48 OK 2_object_stats_trigger.sql (1.04ms)9092026/09/07 10:03:48 goose: up to current file version: 29102026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures9112026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures912--- PASS: TestService_Rustfstest (0.77s)913=== CONT TestClaim_HolderDisconnectKeepsClaim9142026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures9152026-09-07 10:03:49.277 UTC [634] ERROR: relation "goose_db_version" does not exist at character 369162026-09-07 10:03:49.277 UTC [634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9172026/09/07 10:03:49 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9182026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures919--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.87s)920=== CONT TestReadProxyConditionalGet9212026/09/07 10:03:49 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"922--- PASS: TestService_AuthMiddleware (0.87s)923=== CONT TestClaim_TooManyStreams9242026/09/07 10:03:49 OK 20241026095416_initial_model.sql (11.54ms)9252026/09/07 10:03:49 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)9262026/09/07 10:03:49 OK 20251218171726_add_pins.sql (3.84ms)9272026/09/07 10:03:49 OK 20260628120000_add_object_size_and_stats.sql (5.07ms)9282026/09/07 10:03:49 OK 20260905000000_add_claims.sql (4.77ms)9292026/09/07 10:03:49 goose: successfully migrated database to version: 202609050000009302026/09/07 10:03:49 OK 1_commit_pending_closure.sql (4.11ms)9312026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures9322026/09/07 10:03:49 OK 2_object_stats_trigger.sql (2.87ms)9332026/09/07 10:03:49 goose: up to current file version: 29342026-09-07 10:03:49.365 UTC [640] ERROR: relation "goose_db_version" does not exist at character 369352026-09-07 10:03:49.365 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9362026-09-07 10:03:49.368 UTC [641] ERROR: relation "goose_db_version" does not exist at character 369372026-09-07 10:03:49.368 UTC [641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9382026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures9392026/09/07 10:03:49 OK 20241026095416_initial_model.sql (9.99ms)9402026/09/07 10:03:49 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)9412026/09/07 10:03:49 OK 20241026095416_initial_model.sql (15.46ms)9422026/09/07 10:03:49 OK 20251218171726_add_pins.sql (7.67ms)9432026/09/07 10:03:49 OK 20251210153512_drop_unused_gin_index.sql (4.14ms)9442026/09/07 10:03:49 OK 20260628120000_add_object_size_and_stats.sql (7.03ms)9452026/09/07 10:03:49 OK 20251218171726_add_pins.sql (4.57ms)946=== NAME TestClientIntegration947 client_integration_test.go:277: Created store path: /build/TestClientIntegration2140799139/002/store/0phbbqxcxnw6xwknknbqh4v4iqi155pi-test-file.txt9482026/09/07 10:03:49 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)9492026/09/07 10:03:49 OK 20260905000000_add_claims.sql (4.11ms)9502026/09/07 10:03:49 goose: successfully migrated database to version: 202609050000009512026/09/07 10:03:49 OK 20260905000000_add_claims.sql (4.91ms)9522026/09/07 10:03:49 goose: successfully migrated database to version: 202609050000009532026/09/07 10:03:49 OK 1_commit_pending_closure.sql (6.52ms)9542026/09/07 10:03:49 OK 2_object_stats_trigger.sql (1.31ms)9552026/09/07 10:03:49 goose: up to current file version: 29562026/09/07 10:03:49 OK 1_commit_pending_closure.sql (2.77ms)9572026/09/07 10:03:49 OK 2_object_stats_trigger.sql (6.22ms)9582026/09/07 10:03:49 goose: up to current file version: 29592026/09/07 10:03:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9602026/09/07 10:03:49 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWQxYjI2ZDktYjZmOC00YjRkLWFjN2UtOGM3NTFhZDBkNWJjLjExMDU3YTA0LWU2MjYtNGQxMi1hMmRlLWZiMjc1MTNiMjkyY3gxNzg4Nzc1NDI5Mzk1Mzg5MTIw9612026/09/07 10:03:49 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWQxYjI2ZDktYjZmOC00YjRkLWFjN2UtOGM3NTFhZDBkNWJjLjExMDU3YTA0LWU2MjYtNGQxMi1hMmRlLWZiMjc1MTNiMjkyY3gxNzg4Nzc1NDI5Mzk1Mzg5MTIw parts=1962--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.03s)963=== CONT TestReadRedirectUsesPublicS3URL9642026/09/07 10:03:49 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9652026-09-07 10:03:49.530 UTC [714] ERROR: relation "goose_db_version" does not exist at character 369662026-09-07 10:03:49.530 UTC [714] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9672026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures9682026/09/07 10:03:49 WARN claim: cannot clear write deadline error="feature not supported"9692026/09/07 10:03:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9702026/09/07 10:03:49 INFO Uploading 0phbbqxcxnw6xwknknbqh4v4iqi155pi-test-file.txt (152B)9712026/09/07 10:03:49 OK 20241026095416_initial_model.sql (14.28ms)9722026/09/07 10:03:49 WARN claim: cannot clear write deadline error="feature not supported"9732026/09/07 10:03:49 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)974--- PASS: TestClaim_StaleHeartbeatStolen (1.13s)975=== CONT TestClaim_GCMarkedOutputCountsAsAbsent9762026/09/07 10:03:49 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"9772026/09/07 10:03:49 OK 20251218171726_add_pins.sql (6.01ms)9782026/09/07 10:03:49 WARN Failed to register uploaded object key=0phbbqxcxnw6xwknknbqh4v4iqi155pi.ls error="server returned 404: 404 page not found\n"9792026/09/07 10:03:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9802026/09/07 10:03:49 INFO Signed narinfos id=1 count=19812026/09/07 10:03:49 INFO Uploading 1 narinfos9822026/09/07 10:03:49 OK 20260628120000_add_object_size_and_stats.sql (5.83ms)9832026/09/07 10:03:49 OK 20260905000000_add_claims.sql (8.57ms)9842026/09/07 10:03:49 goose: successfully migrated database to version: 202609050000009852026/09/07 10:03:49 OK 1_commit_pending_closure.sql (4.71ms)9862026/09/07 10:03:49 OK 2_object_stats_trigger.sql (3.21ms)9872026/09/07 10:03:49 goose: up to current file version: 29882026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures989--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.22s)990=== CONT TestReadProxyRangeRequest9912026-09-07 10:03:49.642 UTC [736] ERROR: relation "goose_db_version" does not exist at character 369922026-09-07 10:03:49.642 UTC [736] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9932026/09/07 10:03:49 OK 20241026095416_initial_model.sql (11.33ms)9942026/09/07 10:03:49 OK 20251210153512_drop_unused_gin_index.sql (3.32ms)9952026/09/07 10:03:49 OK 20251218171726_add_pins.sql (5.04ms)9962026/09/07 10:03:49 OK 20260628120000_add_object_size_and_stats.sql (6.33ms)997=== NAME TestClientWithDependencies998 client_integration_test.go:594: Built derivation: /build/TestClientWithDependencies4130878201/001/store/dzmbfkvbyyp9g0xz60zl2k5bk5118k3r-test-script9992026/09/07 10:03:49 OK 20260905000000_add_claims.sql (6.52ms)10002026/09/07 10:03:49 goose: successfully migrated database to version: 2026090500000010012026/09/07 10:03:49 WARN Failed to register uploaded object key=0phbbqxcxnw6xwknknbqh4v4iqi155pi.narinfo error="server returned 404: 404 page not found\n"10022026/09/07 10:03:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10032026/09/07 10:03:49 OK 1_commit_pending_closure.sql (5.36ms)10042026/09/07 10:03:49 OK 2_object_stats_trigger.sql (3.45ms)10052026/09/07 10:03:49 goose: up to current file version: 21006=== NAME TestClientMultipleUploads1007 client_integration_test.go:339: Created store path 0: /build/TestClientMultipleUploads945301496/001/store/1chfp6k5zqcb8czl9vf34ifsrq9ql3a4-test-file-0.txt10082026/09/07 10:03:49 INFO Completed upload id=110092026/09/07 10:03:49 INFO Upload complete. (257ms)10102026/09/07 10:03:49 WARN claim: cannot clear write deadline error="feature not supported"1011=== NAME TestClientIntegration1012 client_integration_test.go:293: Retrieved narinfo from S3:1013 StorePath: /build/TestClientIntegration2140799139/002/store/0phbbqxcxnw6xwknknbqh4v4iqi155pi-test-file.txt1014 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1015 Compression: zstd1016 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11017 NarSize: 1521018 References: 1019 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11020 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1021 client_integration_test.go:294: Decompressed .ls content (64 bytes):1022 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1023 client_integration_test.go:297: Testing garbage collection...1024=== NAME TestClientWithDependencies1025 client_integration_test.go:596: Found 1 dependencies (including self)10262026-09-07 10:03:49.722 UTC [793] ERROR: relation "goose_db_version" does not exist at character 3610272026-09-07 10:03:49.722 UTC [793] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10282026/09/07 10:03:49 WARN claim: cannot clear write deadline error="feature not supported"1029--- PASS: TestClaim_FailWithoutKindReleases (1.29s)1030=== CONT TestParseSingleRange1031=== RUN TestParseSingleRange/none1032=== PAUSE TestParseSingleRange/none1033=== RUN TestParseSingleRange/unknown_unit1034=== PAUSE TestParseSingleRange/unknown_unit1035=== RUN TestParseSingleRange/multi-range_ignored1036=== PAUSE TestParseSingleRange/multi-range_ignored1037=== RUN TestParseSingleRange/malformed_no_dash1038=== PAUSE TestParseSingleRange/malformed_no_dash1039=== RUN TestParseSingleRange/malformed_both_empty1040=== PAUSE TestParseSingleRange/malformed_both_empty1041=== RUN TestParseSingleRange/malformed_end_before_start1042=== PAUSE TestParseSingleRange/malformed_end_before_start1043=== RUN TestParseSingleRange/closed1044=== PAUSE TestParseSingleRange/closed1045=== RUN TestParseSingleRange/open-ended1046=== PAUSE TestParseSingleRange/open-ended1047=== RUN TestParseSingleRange/end_clamped_to_size1048=== PAUSE TestParseSingleRange/end_clamped_to_size1049=== RUN TestParseSingleRange/suffix1050=== PAUSE TestParseSingleRange/suffix1051=== RUN TestParseSingleRange/suffix_exceeds_size1052=== PAUSE TestParseSingleRange/suffix_exceeds_size1053=== RUN TestParseSingleRange/single_byte1054=== PAUSE TestParseSingleRange/single_byte1055=== RUN TestParseSingleRange/start_past_EOF1056=== PAUSE TestParseSingleRange/start_past_EOF1057=== RUN TestParseSingleRange/start_far_past_EOF1058=== PAUSE TestParseSingleRange/start_far_past_EOF1059=== CONT TestReadRedirectKeepsNarinfoProxied10602026/09/07 10:03:49 WARN claim: cannot clear write deadline error="feature not supported"1061=== NAME TestClientMultipleUploads1062 client_integration_test.go:339: Created store path 1: /build/TestClientMultipleUploads945301496/001/store/a3hg6mnnp4vnrcdpzns8pfn1qff1v4g7-test-file-1.txt10632026/09/07 10:03:49 OK 20241026095416_initial_model.sql (17.18ms)10642026/09/07 10:03:49 OK 20251210153512_drop_unused_gin_index.sql (4.4ms)10652026/09/07 10:03:49 OK 20251218171726_add_pins.sql (5.68ms)10662026/09/07 10:03:49 WARN claim: cannot clear write deadline error="feature not supported"10672026/09/07 10:03:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures10682026/09/07 10:03:49 INFO Garbage collection started10692026/09/07 10:03:49 OK 20260628120000_add_object_size_and_stats.sql (7.69ms)10702026/09/07 10:03:49 WARN claim: cannot clear write deadline error="feature not supported"10712026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures10722026/09/07 10:03:49 OK 20260905000000_add_claims.sql (5.4ms)10732026/09/07 10:03:49 goose: successfully migrated database to version: 2026090500000010742026/09/07 10:03:49 OK 1_commit_pending_closure.sql (3.45ms)10752026/09/07 10:03:49 INFO Aborted multipart uploads count=010762026/09/07 10:03:49 OK 2_object_stats_trigger.sql (2.18ms)10772026/09/07 10:03:49 goose: up to current file version: 210782026/09/07 10:03:49 WARN claim: cannot clear write deadline error="feature not supported"10792026/09/07 10:03:49 WARN Force mode enabled - objects will be deleted immediately without grace period1080=== NAME TestPinProtectsFromGC1081 client_integration_test.go:648: Pinned store path: /build/TestPinProtectsFromGC1001420979/001/store/vn983h337h20925vg4ajip9464cv4qf9-pinned-file.txt1082 client_integration_test.go:649: Unpinned store path: /build/TestPinProtectsFromGC1001420979/001/store/3gcdx43rwrihiv2ydhr35y6mlp8ps6kx-unpinned-file.txt1083=== NAME TestClientMultipleUploads1084 client_integration_test.go:339: Created store path 2: /build/TestClientMultipleUploads945301496/001/store/ynz7n87m1wy0ygbs5ng6z1snahvjic2d-test-file-2.txt10852026/09/07 10:03:49 WARN claim: cannot clear write deadline error="feature not supported"10862026/09/07 10:03:49 WARN claim: cannot clear write deadline error="feature not supported"1087--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (1.35s)1088=== CONT TestReadRedirectNar10892026-09-07 10:03:49.805 UTC [908] ERROR: relation "goose_db_version" does not exist at character 3610902026-09-07 10:03:49.805 UTC [908] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10912026/09/07 10:03:49 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10922026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures10932026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures1094--- PASS: TestClaim_StreamsThroughServer (1.41s)1095=== CONT TestReadProxyHead10962026/09/07 10:03:49 OK 20241026095416_initial_model.sql (12.29ms)10972026/09/07 10:03:49 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)10982026/09/07 10:03:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10992026/09/07 10:03:49 INFO Uploading dzmbfkvbyyp9g0xz60zl2k5bk5118k3r-test-script (136B)11002026/09/07 10:03:49 OK 20251218171726_add_pins.sql (3.14ms)11012026/09/07 10:03:49 OK 20260628120000_add_object_size_and_stats.sql (7.78ms)11022026/09/07 10:03:49 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11032026/09/07 10:03:49 WARN Failed to register uploaded object key=log/x7fy78g2av5fmlvzina3kkxl4zk00h1g-test-script.drv error="server returned 404: 404 page not found\n"11042026/09/07 10:03:49 OK 20260905000000_add_claims.sql (6.4ms)11052026/09/07 10:03:49 goose: successfully migrated database to version: 2026090500000011062026/09/07 10:03:49 WARN Failed to register uploaded object key=dzmbfkvbyyp9g0xz60zl2k5bk5118k3r.ls error="server returned 404: 404 page not found\n"11072026/09/07 10:03:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11082026/09/07 10:03:49 INFO Signed narinfos id=1 count=111092026/09/07 10:03:49 INFO Uploading 1 narinfos11102026/09/07 10:03:49 OK 1_commit_pending_closure.sql (3.05ms)11112026/09/07 10:03:49 OK 2_object_stats_trigger.sql (1.46ms)11122026/09/07 10:03:49 goose: up to current file version: 211132026/09/07 10:03:49 WARN Failed to register uploaded object key=dzmbfkvbyyp9g0xz60zl2k5bk5118k3r.narinfo error="server returned 404: 404 page not found\n"11142026/09/07 10:03:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11152026/09/07 10:03:49 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11162026/09/07 10:03:49 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11172026/09/07 10:03:49 INFO Completed upload id=111182026/09/07 10:03:49 INFO Upload complete. (99ms)11192026/09/07 10:03:49 INFO Aborted multipart uploads count=011202026/09/07 10:03:49 WARN Force mode enabled - objects will be deleted immediately without grace period11212026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures11222026/09/07 10:03:49 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011232026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures11242026/09/07 10:03:49 INFO Vacuumed table table=pending_closures11252026/09/07 10:03:49 INFO Vacuumed table table=pending_objects11262026/09/07 10:03:49 INFO Vacuumed table table=multipart_uploads11272026/09/07 10:03:49 INFO Vacuumed table table=closures11282026/09/07 10:03:49 INFO Vacuumed table table=objects11292026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures11302026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures11312026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures11322026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures11332026/09/07 10:03:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11342026/09/07 10:03:49 INFO Uploading vn983h337h20925vg4ajip9464cv4qf9-pinned-file.txt (128B)11352026/09/07 10:03:49 INFO Received uploads request method=POST path=/api/pending_closures1136--- PASS: TestGCMetrics (1.49s)1137=== CONT TestReadProxyDisabled11382026/09/07 10:03:49 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11392026/09/07 10:03:49 INFO Uploading a3hg6mnnp4vnrcdpzns8pfn1qff1v4g7-test-file-1.txt (160B)11402026/09/07 10:03:49 INFO Uploading ynz7n87m1wy0ygbs5ng6z1snahvjic2d-test-file-2.txt (160B)11412026/09/07 10:03:49 INFO Uploading 1chfp6k5zqcb8czl9vf34ifsrq9ql3a4-test-file-0.txt (160B)11422026-09-07 10:03:49.929 UTC [1040] ERROR: relation "goose_db_version" does not exist at character 3611432026-09-07 10:03:49.929 UTC [1040] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11442026-09-07 10:03:49.934 UTC [1042] ERROR: relation "goose_db_version" does not exist at character 3611452026-09-07 10:03:49.934 UTC [1042] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11462026/09/07 10:03:49 OK 20241026095416_initial_model.sql (12.93ms)11472026/09/07 10:03:49 OK 20251210153512_drop_unused_gin_index.sql (3.56ms)11482026/09/07 10:03:49 OK 20241026095416_initial_model.sql (14.26ms)11492026/09/07 10:03:49 OK 20251218171726_add_pins.sql (6.56ms)11502026/09/07 10:03:49 OK 20251210153512_drop_unused_gin_index.sql (7.78ms)11512026/09/07 10:03:49 OK 20260628120000_add_object_size_and_stats.sql (8.27ms)11522026/09/07 10:03:49 OK 20251218171726_add_pins.sql (5.41ms)11532026/09/07 10:03:49 OK 20260905000000_add_claims.sql (4.27ms)11542026/09/07 10:03:49 goose: successfully migrated database to version: 2026090500000011552026/09/07 10:03:49 OK 1_commit_pending_closure.sql (3.18ms)11562026/09/07 10:03:49 OK 20260628120000_add_object_size_and_stats.sql (5.99ms)11572026/09/07 10:03:49 OK 2_object_stats_trigger.sql (2.79ms)11582026/09/07 10:03:49 goose: up to current file version: 211592026/09/07 10:03:49 OK 20260905000000_add_claims.sql (4.09ms)11602026/09/07 10:03:49 goose: successfully migrated database to version: 2026090500000011612026/09/07 10:03:49 OK 1_commit_pending_closure.sql (2.16ms)11622026/09/07 10:03:49 OK 2_object_stats_trigger.sql (929.57µs)11632026/09/07 10:03:49 goose: up to current file version: 211642026-09-07 10:03:49.995 UTC [1044] ERROR: relation "goose_db_version" does not exist at character 3611652026-09-07 10:03:49.995 UTC [1044] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11662026/09/07 10:03:50 OK 20241026095416_initial_model.sql (11.41ms)11672026/09/07 10:03:50 OK 20251210153512_drop_unused_gin_index.sql (6.63ms)11682026/09/07 10:03:50 OK 20251218171726_add_pins.sql (4.22ms)11692026/09/07 10:03:50 OK 20260628120000_add_object_size_and_stats.sql (3.32ms)11702026/09/07 10:03:50 OK 20260905000000_add_claims.sql (3.91ms)11712026/09/07 10:03:50 goose: successfully migrated database to version: 2026090500000011722026/09/07 10:03:50 OK 1_commit_pending_closure.sql (2.33ms)11732026/09/07 10:03:50 OK 2_object_stats_trigger.sql (1.03ms)11742026/09/07 10:03:50 goose: up to current file version: 21175--- PASS: TestGCBugBareHashReferences (1.67s)1176=== CONT TestReadProxyInvalidPath11772026-09-07 10:03:50.167 UTC [1047] ERROR: relation "goose_db_version" does not exist at character 3611782026-09-07 10:03:50.167 UTC [1047] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11792026/09/07 10:03:50 OK 20241026095416_initial_model.sql (10.63ms)11802026/09/07 10:03:50 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)11812026/09/07 10:03:50 OK 20251218171726_add_pins.sql (4.01ms)11822026/09/07 10:03:50 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)11832026/09/07 10:03:50 OK 20260905000000_add_claims.sql (3.1ms)11842026/09/07 10:03:50 goose: successfully migrated database to version: 2026090500000011852026/09/07 10:03:50 OK 1_commit_pending_closure.sql (2.31ms)11862026/09/07 10:03:50 OK 2_object_stats_trigger.sql (966.77µs)11872026/09/07 10:03:50 goose: up to current file version: 211882026/09/07 10:03:50 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11892026/09/07 10:03:50 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11902026/09/07 10:03:50 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11912026/09/07 10:03:50 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11922026/09/07 10:03:50 WARN Failed to register uploaded object key=1chfp6k5zqcb8czl9vf34ifsrq9ql3a4.ls error="server returned 404: 404 page not found\n"11932026/09/07 10:03:50 WARN Failed to register uploaded object key=ynz7n87m1wy0ygbs5ng6z1snahvjic2d.ls error="server returned 404: 404 page not found\n"11942026/09/07 10:03:50 WARN Failed to register uploaded object key=vn983h337h20925vg4ajip9464cv4qf9.ls error="server returned 404: 404 page not found\n"11952026/09/07 10:03:50 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11962026/09/07 10:03:50 INFO Signed narinfos id=1 count=111972026/09/07 10:03:50 INFO Uploading 1 narinfos11982026/09/07 10:03:50 WARN Failed to register uploaded object key=vn983h337h20925vg4ajip9464cv4qf9.narinfo error="server returned 404: 404 page not found\n"11992026/09/07 10:03:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12002026/09/07 10:03:50 INFO Completed upload id=112012026/09/07 10:03:50 INFO Upload complete. (869ms)12022026/09/07 10:03:50 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12032026/09/07 10:03:50 WARN Failed to register uploaded object key=a3hg6mnnp4vnrcdpzns8pfn1qff1v4g7.ls error="server returned 404: 404 page not found\n"12042026/09/07 10:03:50 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12052026/09/07 10:03:50 INFO Signed narinfos id=1 count=112062026/09/07 10:03:50 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12072026/09/07 10:03:50 INFO Signed narinfos id=2 count=112082026/09/07 10:03:50 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign12092026/09/07 10:03:50 INFO Signed narinfos id=3 count=112102026/09/07 10:03:50 INFO Uploading 3 narinfos12112026/09/07 10:03:50 WARN Failed to register uploaded object key=1chfp6k5zqcb8czl9vf34ifsrq9ql3a4.narinfo error="server returned 404: 404 page not found\n"12122026/09/07 10:03:50 WARN Failed to register uploaded object key=a3hg6mnnp4vnrcdpzns8pfn1qff1v4g7.narinfo error="server returned 404: 404 page not found\n"12132026/09/07 10:03:50 WARN Failed to register uploaded object key=ynz7n87m1wy0ygbs5ng6z1snahvjic2d.narinfo error="server returned 404: 404 page not found\n"12142026/09/07 10:03:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1215=== NAME TestClientWithDependencies1216 client_integration_test.go:598: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4130878201/001/store) requires matching store prefix12172026/09/07 10:03:50 INFO Completed upload id=112182026/09/07 10:03:50 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12192026/09/07 10:03:50 INFO Completed upload id=21220--- PASS: TestClientWithDependencies (2.38s)1221=== CONT TestReadProxyRootRedirectsToIndexHTML12222026/09/07 10:03:50 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete12232026/09/07 10:03:50 INFO Completed upload id=312242026/09/07 10:03:50 INFO Upload complete. (977ms)1225=== NAME TestClientMultipleUploads1226 client_integration_test.go:350: Uploaded 3 paths in 1.017426312s12272026/09/07 10:03:50 INFO Received uploads request method=POST path=/api/pending_closures12282026/09/07 10:03:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12292026/09/07 10:03:50 INFO Uploading 3gcdx43rwrihiv2ydhr35y6mlp8ps6kx-unpinned-file.txt (128B)12302026/09/07 10:03:50 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"1231--- PASS: TestClientMultipleUploads (2.40s)1232=== CONT TestClaim_BuildWaitComplete12332026/09/07 10:03:50 WARN Failed to register uploaded object key=3gcdx43rwrihiv2ydhr35y6mlp8ps6kx.ls error="server returned 404: 404 page not found\n"12342026/09/07 10:03:50 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12352026/09/07 10:03:50 INFO Signed narinfos id=2 count=112362026/09/07 10:03:50 INFO Uploading 1 narinfos12372026/09/07 10:03:50 WARN Failed to register uploaded object key=3gcdx43rwrihiv2ydhr35y6mlp8ps6kx.narinfo error="server returned 404: 404 page not found\n"12382026/09/07 10:03:50 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12392026/09/07 10:03:50 INFO Completed upload id=212402026/09/07 10:03:50 INFO Upload complete. (119ms)12412026-09-07 10:03:50.883 UTC [1107] ERROR: relation "goose_db_version" does not exist at character 3612422026-09-07 10:03:50.883 UTC [1107] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12432026/09/07 10:03:50 INFO Received create pin request method=POST path=/api/pins/myapp12442026/09/07 10:03:50 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1001420979/001/store/vn983h337h20925vg4ajip9464cv4qf9-pinned-file.txt narinfo_key=vn983h337h20925vg4ajip9464cv4qf9.narinfo12452026/09/07 10:03:50 INFO Starting cleanup of old closures method=DELETE path=/api/closures12462026/09/07 10:03:50 INFO Garbage collection started12472026/09/07 10:03:50 OK 20241026095416_initial_model.sql (16.05ms)12482026-09-07 10:03:50.910 UTC [1125] ERROR: relation "goose_db_version" does not exist at character 3612492026-09-07 10:03:50.910 UTC [1125] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12502026/09/07 10:03:50 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)12512026/09/07 10:03:50 OK 20251218171726_add_pins.sql (4.07ms)12522026/09/07 10:03:50 INFO Aborted multipart uploads count=012532026/09/07 10:03:50 OK 20260628120000_add_object_size_and_stats.sql (5.14ms)12542026/09/07 10:03:50 WARN Force mode enabled - objects will be deleted immediately without grace period12552026/09/07 10:03:50 OK 20260905000000_add_claims.sql (11.13ms)12562026/09/07 10:03:50 goose: successfully migrated database to version: 2026090500000012572026/09/07 10:03:50 OK 20241026095416_initial_model.sql (16.85ms)12582026/09/07 10:03:50 OK 1_commit_pending_closure.sql (2.42ms)12592026/09/07 10:03:50 OK 2_object_stats_trigger.sql (1.31ms)12602026/09/07 10:03:50 goose: up to current file version: 212612026/09/07 10:03:50 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)12622026/09/07 10:03:50 OK 20251218171726_add_pins.sql (4.94ms)12632026/09/07 10:03:50 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)12642026/09/07 10:03:50 OK 20260905000000_add_claims.sql (3.52ms)12652026/09/07 10:03:50 goose: successfully migrated database to version: 2026090500000012662026/09/07 10:03:50 OK 1_commit_pending_closure.sql (2.82ms)12672026/09/07 10:03:50 OK 2_object_stats_trigger.sql (1.11ms)12682026/09/07 10:03:50 goose: up to current file version: 212692026/09/07 10:03:51 INFO Received uploads request method=POST path=/api/pending_closures12702026/09/07 10:03:51 INFO Received cleanup request method=DELETE path=/api/pending_closures12712026/09/07 10:03:51 INFO Aborted multipart uploads count=012722026/09/07 10:03:51 INFO Received uploads request method=POST path=/api/pending_closures12732026/09/07 10:03:51 INFO Received cleanup request method=DELETE path=/api/pending_closures12742026/09/07 10:03:51 INFO Aborted multipart uploads count=112752026/09/07 10:03:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12762026-09-07 10:03:51.702 UTC [630] ERROR: Closure does not exist: id=112772026-09-07 10:03:51.702 UTC [630] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12782026-09-07 10:03:51.702 UTC [630] STATEMENT: -- name: CommitPendingClosure :exec1279 SELECT commit_pending_closure($1::bigint)1280 1281--- PASS: TestService_cleanupPendingClosuresHandler (3.09s)1282=== CONT TestReadProxy40412832026/09/07 10:03:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12842026/09/07 10:03:51 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1285--- PASS: TestCompleteMultipartUnregistered (3.30s)1286=== CONT TestMetricsInventory1287=== NAME TestClientCADerivations1288 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2027237635/001/store/13rvld0f1cy285b7ykwzwvlsid2hf8z0-ca-test12892026/09/07 10:03:51 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=0 objects_failed=012902026-09-07 10:03:51.767 UTC [1178] ERROR: relation "goose_db_version" does not exist at character 3612912026-09-07 10:03:51.767 UTC [1178] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12922026/09/07 10:03:51 WARN claim: cannot clear write deadline error="feature not supported"1293 client_ca_test.go:139: Found 1 dependencies (including self)12942026/09/07 10:03:51 WARN claim: cannot clear write deadline error="feature not supported"12952026/09/07 10:03:51 OK 20241026095416_initial_model.sql (12.61ms)12962026/09/07 10:03:51 OK 20251210153512_drop_unused_gin_index.sql (2.75ms)12972026/09/07 10:03:51 OK 20251218171726_add_pins.sql (6.62ms)12982026/09/07 10:03:51 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)12992026/09/07 10:03:51 WARN claim: cannot clear write deadline error="feature not supported"13002026/09/07 10:03:51 OK 20260905000000_add_claims.sql (4.3ms)13012026/09/07 10:03:51 goose: successfully migrated database to version: 2026090500000013022026/09/07 10:03:51 OK 1_commit_pending_closure.sql (2.07ms)13032026/09/07 10:03:51 OK 2_object_stats_trigger.sql (920.43µs)13042026/09/07 10:03:51 goose: up to current file version: 213052026-09-07 10:03:51.814 UTC [1197] ERROR: relation "goose_db_version" does not exist at character 3613062026-09-07 10:03:51.814 UTC [1197] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1307--- PASS: TestClaim_TooManyStreams (2.54s)1308=== CONT TestCacheStatsHandler13092026/09/07 10:03:51 OK 20241026095416_initial_model.sql (12.61ms)13102026/09/07 10:03:51 OK 20251210153512_drop_unused_gin_index.sql (9.82ms)13112026/09/07 10:03:51 OK 20251218171726_add_pins.sql (6.35ms)13122026/09/07 10:03:51 OK 20260628120000_add_object_size_and_stats.sql (10.12ms)1313--- PASS: TestReadProxyConditionalGet (2.58s)1314=== CONT TestResurrectedObjectNotDeleted13152026/09/07 10:03:51 OK 20260905000000_add_claims.sql (6.47ms)13162026/09/07 10:03:51 goose: successfully migrated database to version: 2026090500000013172026/09/07 10:03:51 OK 1_commit_pending_closure.sql (5.52ms)13182026/09/07 10:03:51 OK 2_object_stats_trigger.sql (3.54ms)13192026/09/07 10:03:51 goose: up to current file version: 213202026/09/07 10:03:51 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13212026-09-07 10:03:51.896 UTC [1239] ERROR: relation "goose_db_version" does not exist at character 3613222026-09-07 10:03:51.896 UTC [1239] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1323--- PASS: TestReadRedirectUsesPublicS3URL (2.47s)1324=== CONT TestReadProxyNarStreaming13252026/09/07 10:03:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13262026/09/07 10:03:51 INFO Received uploads request method=POST path=/api/pending_closures13272026/09/07 10:03:51 OK 20241026095416_initial_model.sql (20.55ms)13282026/09/07 10:03:51 OK 20251210153512_drop_unused_gin_index.sql (4.07ms)13292026/09/07 10:03:51 OK 20251218171726_add_pins.sql (3.28ms)13302026/09/07 10:03:51 OK 20260628120000_add_object_size_and_stats.sql (6.67ms)13312026-09-07 10:03:51.943 UTC [1250] ERROR: relation "goose_db_version" does not exist at character 3613322026-09-07 10:03:51.943 UTC [1250] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13332026/09/07 10:03:51 OK 20260905000000_add_claims.sql (5.28ms)13342026/09/07 10:03:51 goose: successfully migrated database to version: 2026090500000013352026/09/07 10:03:51 OK 1_commit_pending_closure.sql (5.56ms)13362026/09/07 10:03:51 OK 2_object_stats_trigger.sql (3.43ms)13372026/09/07 10:03:51 goose: up to current file version: 213382026/09/07 10:03:51 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=ZWQxYjI2ZDktYjZmOC00YjRkLWFjN2UtOGM3NTFhZDBkNWJjLmQ3YjIyYTUzLTQ5YzMtNGQzNy1hMDczLWY5OWE0NTg3YzJmZHgxNzg4Nzc1NDI5Nzc1MTM0ODg0 parts=1013392026/09/07 10:03:51 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13402026/09/07 10:03:51 INFO Signed narinfos id=1 count=113412026/09/07 10:03:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13422026/09/07 10:03:51 INFO Received uploads request method=POST path=/api/pending_closures13432026/09/07 10:03:51 INFO Completed upload id=113442026/09/07 10:03:51 OK 20241026095416_initial_model.sql (14.31ms)1345--- PASS: TestClaim_TwoInstances (3.53s)1346=== CONT TestCacheConfigHandler1347=== RUN TestCacheConfigHandler/full_config,_no_issuer1348=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1349=== RUN TestCacheConfigHandler/no_cache_url_configured1350=== PAUSE TestCacheConfigHandler/no_cache_url_configured1351=== RUN TestCacheConfigHandler/no_signing_keys1352=== PAUSE TestCacheConfigHandler/no_signing_keys1353=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1354=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1355=== CONT TestOrphanedObjectsGCStressTest13562026/09/07 10:03:51 OK 20251210153512_drop_unused_gin_index.sql (3.6ms)13572026/09/07 10:03:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13582026/09/07 10:03:51 INFO Uploading 13rvld0f1cy285b7ykwzwvlsid2hf8z0-ca-test (144B)13592026/09/07 10:03:51 OK 20251218171726_add_pins.sql (6.33ms)13602026/09/07 10:03:51 WARN Failed to register uploaded object key=log/z1m1qf5cwggjx3vznfxsb0j0w26y2rlw-ca-test.drv error="server returned 404: 404 page not found\n"13612026/09/07 10:03:51 OK 20260628120000_add_object_size_and_stats.sql (7.1ms)13622026/09/07 10:03:51 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13632026/09/07 10:03:51 WARN Failed to register uploaded object key=13rvld0f1cy285b7ykwzwvlsid2hf8z0.ls error="server returned 404: 404 page not found\n"13642026-09-07 10:03:51.989 UTC [1271] ERROR: relation "goose_db_version" does not exist at character 3613652026-09-07 10:03:51.989 UTC [1271] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13662026/09/07 10:03:51 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13672026/09/07 10:03:51 INFO Signed narinfos id=1 count=113682026/09/07 10:03:51 INFO Uploading 1 narinfos13692026/09/07 10:03:51 WARN claim: cannot clear write deadline error="feature not supported"13702026/09/07 10:03:51 OK 20260905000000_add_claims.sql (7.18ms)13712026/09/07 10:03:51 goose: successfully migrated database to version: 2026090500000013722026/09/07 10:03:51 OK 1_commit_pending_closure.sql (4.06ms)13732026/09/07 10:03:51 WARN Failed to register uploaded object key=13rvld0f1cy285b7ykwzwvlsid2hf8z0.narinfo error="server returned 404: 404 page not found\n"13742026/09/07 10:03:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13752026/09/07 10:03:51 OK 2_object_stats_trigger.sql (3.29ms)13762026/09/07 10:03:51 goose: up to current file version: 213772026/09/07 10:03:52 INFO Completed upload id=113782026/09/07 10:03:52 INFO Upload complete. (183ms)13792026/09/07 10:03:52 OK 20241026095416_initial_model.sql (12.39ms)13802026/09/07 10:03:52 OK 20251210153512_drop_unused_gin_index.sql (3.26ms)13812026/09/07 10:03:52 OK 20251218171726_add_pins.sql (5.51ms)13822026/09/07 10:03:52 OK 20260628120000_add_object_size_and_stats.sql (5.96ms)13832026/09/07 10:03:52 OK 20260905000000_add_claims.sql (3.5ms)13842026/09/07 10:03:52 goose: successfully migrated database to version: 2026090500000013852026/09/07 10:03:52 OK 1_commit_pending_closure.sql (2.06ms)13862026/09/07 10:03:52 OK 2_object_stats_trigger.sql (960.91µs)13872026/09/07 10:03:52 goose: up to current file version: 213882026-09-07 10:03:52.042 UTC [1272] ERROR: relation "goose_db_version" does not exist at character 3613892026-09-07 10:03:52.042 UTC [1272] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13902026/09/07 10:03:52 OK 20241026095416_initial_model.sql (10.56ms)13912026/09/07 10:03:52 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)13922026/09/07 10:03:52 OK 20251218171726_add_pins.sql (3.71ms)13932026/09/07 10:03:52 OK 20260628120000_add_object_size_and_stats.sql (2.95ms)13942026/09/07 10:03:52 OK 20260905000000_add_claims.sql (3.25ms)13952026/09/07 10:03:52 goose: successfully migrated database to version: 2026090500000013962026/09/07 10:03:52 OK 1_commit_pending_closure.sql (1.98ms)13972026/09/07 10:03:52 OK 2_object_stats_trigger.sql (880.19µs)13982026/09/07 10:03:52 goose: up to current file version: 21399=== NAME TestClientCADerivations1400 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2027237635/001/store/13rvld0f1cy285b7ykwzwvlsid2hf8z0-ca-test1401 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1402 Compression: zstd1403 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1404 NarSize: 1441405 References: 1406 Deriver: /build/TestClientCADerivations2027237635/001/store/z1m1qf5cwggjx3vznfxsb0j0w26y2rlw-ca-test.drv1407 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1408 client_ca_test.go:185: Checking for realisation files in S3...1409 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1410 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1411--- PASS: TestReadProxyRangeRequest (2.57s)1412=== CONT TestReadProxyNarinfoAlreadyDecompressed1413--- PASS: TestReadRedirectKeepsNarinfoProxied (2.50s)1414=== CONT TestService_ReadScope_PublicByDefault1415--- PASS: TestReadProxyHead (2.43s)1416=== CONT TestOrphanedObjectsGC14172026-09-07 10:03:52.293 UTC [1335] ERROR: relation "goose_db_version" does not exist at character 3614182026-09-07 10:03:52.293 UTC [1335] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1419--- PASS: TestReadRedirectNar (2.51s)1420=== CONT TestService_RequireScope_OIDC14212026/09/07 10:03:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37075/oidc14222026/09/07 10:03:52 OK 20241026095416_initial_model.sql (17.54ms)14232026/09/07 10:03:52 OK 20251210153512_drop_unused_gin_index.sql (3.24ms)14242026-09-07 10:03:52.328 UTC [1361] ERROR: relation "goose_db_version" does not exist at character 3614252026-09-07 10:03:52.328 UTC [1361] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1426--- PASS: TestReadProxyDisabled (2.41s)1427=== CONT TestReadProxyNarinfo14282026/09/07 10:03:52 OK 20251218171726_add_pins.sql (13.6ms)14292026/09/07 10:03:52 OK 20260628120000_add_object_size_and_stats.sql (7.72ms)14302026/09/07 10:03:52 OK 20241026095416_initial_model.sql (13.26ms)14312026-09-07 10:03:52.353 UTC [1364] ERROR: relation "goose_db_version" does not exist at character 3614322026-09-07 10:03:52.353 UTC [1364] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14332026/09/07 10:03:52 OK 20251210153512_drop_unused_gin_index.sql (4.57ms)14342026/09/07 10:03:52 OK 20260905000000_add_claims.sql (8.62ms)14352026/09/07 10:03:52 goose: successfully migrated database to version: 2026090500000014362026/09/07 10:03:52 OK 20251218171726_add_pins.sql (6.26ms)14372026/09/07 10:03:52 OK 1_commit_pending_closure.sql (4.44ms)14382026/09/07 10:03:52 OK 2_object_stats_trigger.sql (4.42ms)14392026/09/07 10:03:52 goose: up to current file version: 214402026/09/07 10:03:52 OK 20260628120000_add_object_size_and_stats.sql (5.92ms)14412026/09/07 10:03:52 OK 20260905000000_add_claims.sql (5.96ms)14422026/09/07 10:03:52 goose: successfully migrated database to version: 2026090500000014432026/09/07 10:03:52 OK 1_commit_pending_closure.sql (4ms)14442026/09/07 10:03:52 OK 2_object_stats_trigger.sql (4.03ms)14452026/09/07 10:03:52 OK 20241026095416_initial_model.sql (19.74ms)14462026/09/07 10:03:52 goose: up to current file version: 214472026/09/07 10:03:52 OK 20251210153512_drop_unused_gin_index.sql (3.3ms)14482026/09/07 10:03:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14492026/09/07 10:03:52 OK 20251218171726_add_pins.sql (4.54ms)14502026-09-07 10:03:52.393 UTC [1365] ERROR: relation "goose_db_version" does not exist at character 3614512026-09-07 10:03:52.393 UTC [1365] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14522026/09/07 10:03:52 OK 20260628120000_add_object_size_and_stats.sql (5.58ms)14532026/09/07 10:03:52 OK 20260905000000_add_claims.sql (5.3ms)14542026/09/07 10:03:52 goose: successfully migrated database to version: 2026090500000014552026/09/07 10:03:52 OK 1_commit_pending_closure.sql (3.19ms)14562026/09/07 10:03:52 OK 2_object_stats_trigger.sql (1.64ms)14572026/09/07 10:03:52 goose: up to current file version: 214582026/09/07 10:03:52 OK 20241026095416_initial_model.sql (11.8ms)14592026/09/07 10:03:52 OK 20251210153512_drop_unused_gin_index.sql (2.88ms)14602026/09/07 10:03:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZWQxYjI2ZDktYjZmOC00YjRkLWFjN2UtOGM3NTFhZDBkNWJjLmVkMGU2N2NlLWQwNzEtNGU4NC1iMjU3LTE5ZTYyOGM4ZDMyYngxNzg4Nzc1NDI5MDk1OTYyNTYy parts=121461--- PASS: TestRedundantMultipartUpload (4.01s)1462=== CONT TestObjectStatsTrigger14632026/09/07 10:03:52 OK 20251218171726_add_pins.sql (5.13ms)14642026/09/07 10:03:52 OK 20260628120000_add_object_size_and_stats.sql (5.59ms)14652026/09/07 10:03:52 OK 20260905000000_add_claims.sql (9.98ms)14662026/09/07 10:03:52 goose: successfully migrated database to version: 2026090500000014672026/09/07 10:03:52 OK 1_commit_pending_closure.sql (3.81ms)14682026/09/07 10:03:52 OK 2_object_stats_trigger.sql (5.92ms)14692026/09/07 10:03:52 goose: up to current file version: 21470=== NAME TestClientCADerivations1471 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1472 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1473 error: binary cache 's3://bucket23?endpoint=http://localhost:32881®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2027237635/001/store'1474 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 114752026-09-07 10:03:52.463 UTC [1405] ERROR: relation "goose_db_version" does not exist at character 3614762026-09-07 10:03:52.463 UTC [1405] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1477--- PASS: TestClientCADerivations (4.04s)1478=== CONT TestIsValidCachePath1479=== RUN TestIsValidCachePath/narinfo1480=== PAUSE TestIsValidCachePath/narinfo1481=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1482=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1483=== RUN TestIsValidCachePath/nar_zst1484=== PAUSE TestIsValidCachePath/nar_zst1485=== RUN TestIsValidCachePath/nar_xz1486=== PAUSE TestIsValidCachePath/nar_xz1487=== RUN TestIsValidCachePath/nar_bz21488=== PAUSE TestIsValidCachePath/nar_bz21489=== RUN TestIsValidCachePath/nar_uncompressed1490=== PAUSE TestIsValidCachePath/nar_uncompressed1491=== RUN TestIsValidCachePath/ls1492=== PAUSE TestIsValidCachePath/ls1493=== RUN TestIsValidCachePath/log1494=== PAUSE TestIsValidCachePath/log1495=== RUN TestIsValidCachePath/realisation1496=== PAUSE TestIsValidCachePath/realisation1497=== RUN TestIsValidCachePath/nix-cache-info1498=== PAUSE TestIsValidCachePath/nix-cache-info1499=== RUN TestIsValidCachePath/index.html1500=== PAUSE TestIsValidCachePath/index.html1501=== RUN TestIsValidCachePath/traversal_parent1502=== PAUSE TestIsValidCachePath/traversal_parent1503=== RUN TestIsValidCachePath/traversal_in_middle1504=== PAUSE TestIsValidCachePath/traversal_in_middle1505=== RUN TestIsValidCachePath/invalid_char_e1506=== PAUSE TestIsValidCachePath/invalid_char_e1507=== RUN TestIsValidCachePath/invalid_char_u1508=== PAUSE TestIsValidCachePath/invalid_char_u1509=== RUN TestIsValidCachePath/random_path1510=== PAUSE TestIsValidCachePath/random_path1511=== RUN TestIsValidCachePath/empty1512=== PAUSE TestIsValidCachePath/empty1513=== RUN TestIsValidCachePath/leading_slash1514=== PAUSE TestIsValidCachePath/leading_slash1515=== RUN TestIsValidCachePath/wrong_extension1516=== PAUSE TestIsValidCachePath/wrong_extension1517=== RUN TestIsValidCachePath/short_hash1518=== PAUSE TestIsValidCachePath/short_hash1519=== CONT TestMultipartCleanup15202026/09/07 10:03:52 OK 20241026095416_initial_model.sql (16.98ms)15212026/09/07 10:03:52 OK 20251210153512_drop_unused_gin_index.sql (3.44ms)15222026/09/07 10:03:52 OK 20251218171726_add_pins.sql (6ms)15232026/09/07 10:03:52 OK 20260628120000_add_object_size_and_stats.sql (6.07ms)15242026/09/07 10:03:52 OK 20260905000000_add_claims.sql (5.38ms)15252026/09/07 10:03:52 goose: successfully migrated database to version: 2026090500000015262026/09/07 10:03:52 OK 1_commit_pending_closure.sql (3.81ms)15272026/09/07 10:03:52 OK 2_object_stats_trigger.sql (2.3ms)15282026/09/07 10:03:52 goose: up to current file version: 215292026-09-07 10:03:52.539 UTC [1408] ERROR: relation "goose_db_version" does not exist at character 3615302026-09-07 10:03:52.539 UTC [1408] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15312026-09-07 10:03:52.544 UTC [1409] ERROR: relation "goose_db_version" does not exist at character 3615322026-09-07 10:03:52.544 UTC [1409] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15332026/09/07 10:03:52 OK 20241026095416_initial_model.sql (12.73ms)15342026/09/07 10:03:52 OK 20241026095416_initial_model.sql (10.34ms)15352026/09/07 10:03:52 OK 20251210153512_drop_unused_gin_index.sql (3.4ms)15362026/09/07 10:03:52 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)15372026/09/07 10:03:52 OK 20251218171726_add_pins.sql (4.29ms)15382026/09/07 10:03:52 OK 20251218171726_add_pins.sql (4.21ms)15392026/09/07 10:03:52 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)15402026/09/07 10:03:52 OK 20260628120000_add_object_size_and_stats.sql (4.88ms)15412026/09/07 10:03:52 OK 20260905000000_add_claims.sql (4.04ms)15422026/09/07 10:03:52 goose: successfully migrated database to version: 2026090500000015432026/09/07 10:03:52 OK 20260905000000_add_claims.sql (4.03ms)15442026/09/07 10:03:52 goose: successfully migrated database to version: 2026090500000015452026/09/07 10:03:52 OK 1_commit_pending_closure.sql (2.78ms)15462026/09/07 10:03:52 OK 1_commit_pending_closure.sql (2.93ms)15472026/09/07 10:03:52 OK 2_object_stats_trigger.sql (873.49µs)15482026/09/07 10:03:52 goose: up to current file version: 215492026/09/07 10:03:52 OK 2_object_stats_trigger.sql (974.27µs)15502026/09/07 10:03:52 goose: up to current file version: 215512026/09/07 10:03:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15522026/09/07 10:03:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=ZWQxYjI2ZDktYjZmOC00YjRkLWFjN2UtOGM3NTFhZDBkNWJjLjdjY2ZkZmQ3LTdkMDYtNGNiMy05ZTJjLTliYzkyMDM4YWNiNngxNzg4Nzc1NDI5ODMxMTQxNjYz parts=1015532026/09/07 10:03:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15542026/09/07 10:03:52 INFO Completed upload id=115552026/09/07 10:03:52 WARN claim: cannot clear write deadline error="feature not supported"15562026/09/07 10:03:52 INFO Aborted multipart uploads count=015572026/09/07 10:03:52 WARN Force mode enabled - objects will be deleted immediately without grace period15582026/09/07 10:03:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015592026/09/07 10:03:52 INFO Vacuumed table table=pending_closures15602026/09/07 10:03:52 INFO Vacuumed table table=pending_objects15612026/09/07 10:03:52 INFO Vacuumed table table=multipart_uploads15622026/09/07 10:03:52 INFO Vacuumed table table=closures15632026/09/07 10:03:52 INFO Vacuumed table table=objects1564--- PASS: TestClaim_InputsTouched (4.31s)1565=== CONT TestService_AuthMiddleware_OIDC15662026/09/07 10:03:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41479/oidc1567--- PASS: TestReadProxyInvalidPath (2.69s)1568=== CONT TestServerTLSConfig1569=== RUN TestServerTLSConfig/no_client_CA1570=== PAUSE TestServerTLSConfig/no_client_CA1571=== RUN TestServerTLSConfig/missing_CA_file1572=== PAUSE TestServerTLSConfig/missing_CA_file1573=== RUN TestServerTLSConfig/not_a_PEM_file1574=== PAUSE TestServerTLSConfig/not_a_PEM_file1575=== CONT TestService_AuthMiddleware_MTLSProxyHeader1576--- PASS: TestClaim_HolderDisconnectKeepsClaim (3.60s)1577=== CONT TestService_NativeMTLS15782026/09/07 10:03:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15792026/09/07 10:03:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15802026-09-07 10:03:52.838 UTC [1417] ERROR: relation "goose_db_version" does not exist at character 3615812026-09-07 10:03:52.838 UTC [1417] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1582--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.04s)1583=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15842026/09/07 10:03:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZWQxYjI2ZDktYjZmOC00YjRkLWFjN2UtOGM3NTFhZDBkNWJjLmE2NzhkNjg4LTQ3NTctNDFhOC1hNWNmLTYwMDYwNjAwMGI1ZHgxNzg4Nzc1NDMwNjYwNTg4ODA5 parts=1015852026/09/07 10:03:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15862026/09/07 10:03:52 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZWQxYjI2ZDktYjZmOC00YjRkLWFjN2UtOGM3NTFhZDBkNWJjLmRmNzFlOTIyLTZkMjItNGUzMy1hMGVjLWFkYmQzNjI0NzY5Y3gxNzg4Nzc1NDMxNjE0MjMzODc2 parts=1015872026/09/07 10:03:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15882026/09/07 10:03:52 OK 20241026095416_initial_model.sql (15.1ms)15892026/09/07 10:03:52 INFO Completed upload id=115902026/09/07 10:03:52 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015912026/09/07 10:03:52 INFO Completed upload id=115922026/09/07 10:03:52 INFO Received uploads request method=POST path=/api/pending_closures15932026/09/07 10:03:52 OK 20251210153512_drop_unused_gin_index.sql (3.36ms)15942026/09/07 10:03:52 INFO Received uploads request method=POST path=/api/pending_closures15952026/09/07 10:03:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures15962026/09/07 10:03:52 INFO Received uploads request method=POST path=/api/pending_closures15972026/09/07 10:03:52 OK 20251218171726_add_pins.sql (7.75ms)15982026-09-07 10:03:52.875 UTC [1420] ERROR: relation "goose_db_version" does not exist at character 3615992026-09-07 10:03:52.875 UTC [1420] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16002026/09/07 10:03:52 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16012026/09/07 10:03:52 WARN Found objects in DB but missing from S3, will re-upload count=11602--- PASS: TestService_verifyS3Integrity (4.44s)1603=== CONT TestService_ReadAuthMiddleware16042026/09/07 10:03:52 OK 20260628120000_add_object_size_and_stats.sql (6.16ms)16052026/09/07 10:03:52 INFO Aborted multipart uploads count=016062026/09/07 10:03:52 OK 20260905000000_add_claims.sql (5.47ms)16072026/09/07 10:03:52 goose: successfully migrated database to version: 2026090500000016082026/09/07 10:03:52 OK 1_commit_pending_closure.sql (4.27ms)16092026/09/07 10:03:52 OK 2_object_stats_trigger.sql (3.06ms)16102026/09/07 10:03:52 goose: up to current file version: 216112026/09/07 10:03:52 WARN claim: cannot clear write deadline error="feature not supported"16122026/09/07 10:03:52 OK 20241026095416_initial_model.sql (13.4ms)16132026/09/07 10:03:52 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=0 objects_failed=016142026/09/07 10:03:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=016152026/09/07 10:03:52 OK 20251210153512_drop_unused_gin_index.sql (17.12ms)16162026/09/07 10:03:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16172026/09/07 10:03:52 INFO Vacuumed table table=pending_closures16182026/09/07 10:03:52 OK 20251218171726_add_pins.sql (6.64ms)16192026/09/07 10:03:52 INFO Vacuumed table table=pending_objects16202026/09/07 10:03:52 WARN claim: cannot clear write deadline error="feature not supported"16212026/09/07 10:03:52 WARN claim: cannot clear write deadline error="feature not supported"16222026/09/07 10:03:52 OK 20260628120000_add_object_size_and_stats.sql (7.56ms)16232026/09/07 10:03:52 INFO Received uploads request method=POST path=/api/pending_closures16242026/09/07 10:03:52 INFO Vacuumed table table=multipart_uploads16252026-09-07 10:03:52.933 UTC [1425] ERROR: relation "goose_db_version" does not exist at character 3616262026-09-07 10:03:52.933 UTC [1425] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16272026/09/07 10:03:52 OK 20260905000000_add_claims.sql (4.9ms)16282026/09/07 10:03:52 goose: successfully migrated database to version: 2026090500000016292026/09/07 10:03:52 INFO Vacuumed table table=closures16302026/09/07 10:03:52 OK 1_commit_pending_closure.sql (3.32ms)16312026/09/07 10:03:52 INFO Vacuumed table table=objects16322026/09/07 10:03:52 OK 2_object_stats_trigger.sql (1.5ms)16332026/09/07 10:03:52 goose: up to current file version: 21634--- PASS: TestReadProxy404 (1.24s)1635=== CONT TestService_healthCheckHandler16362026/09/07 10:03:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=ZWQxYjI2ZDktYjZmOC00YjRkLWFjN2UtOGM3NTFhZDBkNWJjLmJhYjI3Y2JmLWFlMGEtNDYzNi1iY2ViLWM3ZWNhN2Y5ZjNlYXgxNzg4Nzc1NDMxOTQzODc3OTkz parts=1016372026/09/07 10:03:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16382026-09-07 10:03:52.952 UTC [1426] ERROR: relation "goose_db_version" does not exist at character 3616392026-09-07 10:03:52.952 UTC [1426] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16402026/09/07 10:03:52 INFO Completed upload id=116412026/09/07 10:03:52 WARN claim: cannot clear write deadline error="feature not supported"16422026/09/07 10:03:52 OK 20241026095416_initial_model.sql (15ms)16432026/09/07 10:03:52 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)16442026/09/07 10:03:52 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001645--- PASS: TestService_createPendingClosureHandler (4.53s)1646=== CONT TestProxyWriteTimeout1647=== RUN TestProxyWriteTimeout/narinfo1648=== PAUSE TestProxyWriteTimeout/narinfo1649=== RUN TestProxyWriteTimeout/1_GiB_nar1650=== PAUSE TestProxyWriteTimeout/1_GiB_nar1651=== RUN TestProxyWriteTimeout/10_GiB_nar1652=== PAUSE TestProxyWriteTimeout/10_GiB_nar1653=== RUN TestProxyWriteTimeout/unknown_size1654=== PAUSE TestProxyWriteTimeout/unknown_size1655=== CONT TestService_readinessHandler16562026/09/07 10:03:52 WARN claim: cannot clear write deadline error="feature not supported"16572026/09/07 10:03:52 OK 20251218171726_add_pins.sql (14.34ms)16582026/09/07 10:03:52 OK 20241026095416_initial_model.sql (14.53ms)16592026/09/07 10:03:52 OK 20251210153512_drop_unused_gin_index.sql (2.9ms)1660--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (3.42s)1661=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle16622026/09/07 10:03:52 OK 20260628120000_add_object_size_and_stats.sql (5.44ms)16632026/09/07 10:03:52 OK 20251218171726_add_pins.sql (4.2ms)16642026/09/07 10:03:52 OK 20260905000000_add_claims.sql (4.86ms)16652026/09/07 10:03:52 goose: successfully migrated database to version: 2026090500000016662026-09-07 10:03:52.985 UTC [1431] ERROR: relation "goose_db_version" does not exist at character 3616672026-09-07 10:03:52.985 UTC [1431] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16682026/09/07 10:03:52 OK 20260628120000_add_object_size_and_stats.sql (4.55ms)16692026/09/07 10:03:52 OK 1_commit_pending_closure.sql (5.49ms)16702026/09/07 10:03:52 OK 20260905000000_add_claims.sql (5.09ms)16712026/09/07 10:03:52 goose: successfully migrated database to version: 2026090500000016722026/09/07 10:03:52 OK 2_object_stats_trigger.sql (3.9ms)16732026/09/07 10:03:52 goose: up to current file version: 216742026/09/07 10:03:52 OK 1_commit_pending_closure.sql (4.41ms)16752026/09/07 10:03:52 OK 2_object_stats_trigger.sql (2.73ms)16762026/09/07 10:03:52 goose: up to current file version: 216772026/09/07 10:03:53 OK 20241026095416_initial_model.sql (13.36ms)1678--- PASS: TestMetricsInventory (1.28s)1679=== CONT TestGracefulShutdownDrainsInflight16802026/09/07 10:03:53 INFO Starting HTTP server address=127.0.0.1:3346116812026/09/07 10:03:53 OK 20251210153512_drop_unused_gin_index.sql (4.02ms)16822026/09/07 10:03:53 INFO Shutdown signal received, draining in-flight requests timeout=10s16832026/09/07 10:03:53 OK 20251218171726_add_pins.sql (5.44ms)16842026/09/07 10:03:53 OK 20260628120000_add_object_size_and_stats.sql (5.69ms)16852026/09/07 10:03:53 OK 20260905000000_add_claims.sql (5.32ms)16862026/09/07 10:03:53 goose: successfully migrated database to version: 2026090500000016872026-09-07 10:03:53.036 UTC [1434] ERROR: relation "goose_db_version" does not exist at character 3616882026-09-07 10:03:53.036 UTC [1434] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16892026/09/07 10:03:53 OK 1_commit_pending_closure.sql (10.02ms)16902026/09/07 10:03:53 OK 2_object_stats_trigger.sql (3.22ms)16912026/09/07 10:03:53 goose: up to current file version: 21692--- PASS: TestCacheStatsHandler (1.22s)1693=== CONT TestUploadHandlersRejectInvalidKeys1694=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1695=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1696=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1697=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1698=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1699=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1700=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1701=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1702=== CONT TestSkippedUploadsHandler17032026/09/07 10:03:53 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001704--- PASS: TestSkippedUploadsHandler (0.01s)1705=== CONT TestIsValidUploadKey1706=== RUN TestIsValidUploadKey/narinfo1707=== PAUSE TestIsValidUploadKey/narinfo1708=== RUN TestIsValidUploadKey/nar_zst1709=== PAUSE TestIsValidUploadKey/nar_zst1710=== RUN TestIsValidUploadKey/nar_xz1711=== PAUSE TestIsValidUploadKey/nar_xz1712=== RUN TestIsValidUploadKey/nar_plain1713=== PAUSE TestIsValidUploadKey/nar_plain1714=== RUN TestIsValidUploadKey/listing1715=== PAUSE TestIsValidUploadKey/listing1716=== RUN TestIsValidUploadKey/build_log1717=== PAUSE TestIsValidUploadKey/build_log1718=== RUN TestIsValidUploadKey/build_log_home-manager_file1719=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1720=== RUN TestIsValidUploadKey/build_log_plus_in_name1721=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1722=== RUN TestIsValidUploadKey/build_log_question_mark1723=== PAUSE TestIsValidUploadKey/build_log_question_mark1724=== RUN TestIsValidUploadKey/build_log_equals1725=== PAUSE TestIsValidUploadKey/build_log_equals1726=== RUN TestIsValidUploadKey/realisation1727=== PAUSE TestIsValidUploadKey/realisation1728=== RUN TestIsValidUploadKey/realisation_plus_in_output1729=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1730=== RUN TestIsValidUploadKey/nix-cache-info1731=== PAUSE TestIsValidUploadKey/nix-cache-info1732=== RUN TestIsValidUploadKey/index.html1733=== PAUSE TestIsValidUploadKey/index.html1734=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1735=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1736=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1737=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1738=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1739=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1740=== RUN TestIsValidUploadKey/traversal1741=== PAUSE TestIsValidUploadKey/traversal1742=== RUN TestIsValidUploadKey/traversal_nar1743=== PAUSE TestIsValidUploadKey/traversal_nar1744=== RUN TestIsValidUploadKey/absolute1745=== PAUSE TestIsValidUploadKey/absolute1746=== RUN TestIsValidUploadKey/empty_key1747=== PAUSE TestIsValidUploadKey/empty_key1748=== RUN TestIsValidUploadKey/unknown_type1749=== PAUSE TestIsValidUploadKey/unknown_type1750=== CONT TestCreatePendingClosureRejectsOversizedNAR17512026/09/07 10:03:53 INFO Received uploads request method=POST path=/api/pending_closures1752--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1753=== CONT TestNARDeduplicationMetadataUploadBug17542026/09/07 10:03:53 OK 20241026095416_initial_model.sql (12.91ms)17552026-09-07 10:03:53.060 UTC [1435] ERROR: relation "goose_db_version" does not exist at character 3617562026-09-07 10:03:53.060 UTC [1435] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17572026/09/07 10:03:53 OK 20251210153512_drop_unused_gin_index.sql (3.39ms)17582026/09/07 10:03:53 OK 20251218171726_add_pins.sql (3.3ms)17592026/09/07 10:03:53 OK 20260628120000_add_object_size_and_stats.sql (4.48ms)17602026/09/07 10:03:53 OK 20260905000000_add_claims.sql (4.98ms)17612026/09/07 10:03:53 goose: successfully migrated database to version: 2026090500000017622026-09-07 10:03:53.078 UTC [1438] ERROR: relation "goose_db_version" does not exist at character 3617632026-09-07 10:03:53.078 UTC [1438] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1764--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1765=== CONT TestGenerateLandingPage17662026/09/07 10:03:53 OK 1_commit_pending_closure.sql (5.06ms)17672026/09/07 10:03:53 OK 20241026095416_initial_model.sql (15.98ms)17682026/09/07 10:03:53 OK 2_object_stats_trigger.sql (3.88ms)17692026/09/07 10:03:53 goose: up to current file version: 217702026/09/07 10:03:53 OK 20251210153512_drop_unused_gin_index.sql (4.45ms)1771--- PASS: TestGenerateLandingPage (0.01s)1772=== CONT TestCacheConfigHandlerMaxNarSize1773--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1774=== CONT TestResolveDBConnectionString/flag_wins1775=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1776=== CONT TestResolveDBConnectionString/nothing_configured1777=== CONT TestResolveDBConnectionString/missing_file_is_an_error1778=== CONT TestResolveDBConnectionString/file_when_flag_empty1779=== CONT TestClientErrorHandling/InvalidStorePath1780--- PASS: TestResolveDBConnectionString (0.00s)1781 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1782 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1783 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1784 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1785 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17862026/09/07 10:03:53 OK 20251218171726_add_pins.sql (6.16ms)17872026/09/07 10:03:53 OK 20260628120000_add_object_size_and_stats.sql (7.16ms)17882026/09/07 10:03:53 OK 20241026095416_initial_model.sql (16.81ms)17892026/09/07 10:03:53 OK 20251210153512_drop_unused_gin_index.sql (2.21ms)17902026/09/07 10:03:53 OK 20260905000000_add_claims.sql (5.11ms)17912026/09/07 10:03:53 goose: successfully migrated database to version: 2026090500000017922026/09/07 10:03:53 OK 1_commit_pending_closure.sql (11.03ms)17932026/09/07 10:03:53 OK 20251218171726_add_pins.sql (14.78ms)17942026/09/07 10:03:53 OK 2_object_stats_trigger.sql (3.25ms)17952026/09/07 10:03:53 goose: up to current file version: 217962026/09/07 10:03:53 OK 20260628120000_add_object_size_and_stats.sql (6.07ms)17972026/09/07 10:03:53 OK 20260905000000_add_claims.sql (5.88ms)17982026/09/07 10:03:53 goose: successfully migrated database to version: 2026090500000017992026/09/07 10:03:53 OK 1_commit_pending_closure.sql (6.19ms)18002026/09/07 10:03:53 OK 2_object_stats_trigger.sql (2.15ms)18012026/09/07 10:03:53 goose: up to current file version: 218022026-09-07 10:03:53.148 UTC [1441] ERROR: relation "goose_db_version" does not exist at character 3618032026-09-07 10:03:53.148 UTC [1441] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18042026/09/07 10:03:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18052026/09/07 10:03:53 OK 20241026095416_initial_model.sql (19.68ms)18062026/09/07 10:03:53 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)18072026/09/07 10:03:53 OK 20251218171726_add_pins.sql (4.11ms)18082026/09/07 10:03:53 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)18092026-09-07 10:03:53.190 UTC [1442] ERROR: relation "goose_db_version" does not exist at character 3618102026-09-07 10:03:53.190 UTC [1442] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18112026/09/07 10:03:53 OK 20260905000000_add_claims.sql (3.8ms)18122026/09/07 10:03:53 goose: successfully migrated database to version: 2026090500000018132026/09/07 10:03:53 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZWQxYjI2ZDktYjZmOC00YjRkLWFjN2UtOGM3NTFhZDBkNWJjLmU4OTM0ZWE5LTI5YzEtNDI0YS05Mjg5LWU2ZjhkZDE0YjRlZngxNzg4Nzc1NDI5MzMyNDAzNzYy parts=1218142026/09/07 10:03:53 OK 1_commit_pending_closure.sql (2.19ms)18152026/09/07 10:03:53 INFO Received uploads request method=POST path=/api/pending_closures18162026/09/07 10:03:53 OK 2_object_stats_trigger.sql (1.05ms)18172026/09/07 10:03:53 goose: up to current file version: 21818--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.78s)1819=== CONT TestClientErrorHandling/ServerNotAvailable18202026/09/07 10:03:53 OK 20241026095416_initial_model.sql (9.15ms)18212026/09/07 10:03:53 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)18222026/09/07 10:03:53 OK 20251218171726_add_pins.sql (3.61ms)18232026/09/07 10:03:53 OK 20260628120000_add_object_size_and_stats.sql (4.02ms)18242026/09/07 10:03:53 OK 20260905000000_add_claims.sql (3.62ms)18252026/09/07 10:03:53 goose: successfully migrated database to version: 2026090500000018262026/09/07 10:03:53 OK 1_commit_pending_closure.sql (2.02ms)18272026/09/07 10:03:53 OK 2_object_stats_trigger.sql (879.43µs)18282026/09/07 10:03:53 goose: up to current file version: 218292026/09/07 10:03:53 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1830--- PASS: TestReadProxyNarStreaming (1.47s)1831=== CONT TestClientErrorHandling/InvalidAuthToken1832--- PASS: TestResurrectedObjectNotDeleted (1.54s)1833=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18342026/09/07 10:03:53 INFO Received uploads request method=POST path=/18352026/09/07 10:03:53 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.570266ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1836--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.24s)1837=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18382026/09/07 10:03:53 INFO Received complete multipart upload request method=POST path=/1839--- PASS: TestService_ReadScope_PublicByDefault (1.23s)1840=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18412026/09/07 10:03:53 INFO Received request for more parts method=POST path=/18422026-09-07 10:03:53.474 UTC [1498] ERROR: relation "goose_db_version" does not exist at character 3618432026-09-07 10:03:53.474 UTC [1498] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18442026/09/07 10:03:53 OK 20241026095416_initial_model.sql (9.88ms)18452026/09/07 10:03:53 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)18462026/09/07 10:03:53 OK 20251218171726_add_pins.sql (3.86ms)18472026/09/07 10:03:53 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)18482026/09/07 10:03:53 OK 20260905000000_add_claims.sql (2.88ms)18492026/09/07 10:03:53 goose: successfully migrated database to version: 2026090500000018502026/09/07 10:03:53 OK 1_commit_pending_closure.sql (2.19ms)18512026/09/07 10:03:53 OK 2_object_stats_trigger.sql (867.51µs)18522026/09/07 10:03:53 goose: up to current file version: 21853=== CONT TestParseSingleRange/none1854=== CONT TestParseSingleRange/open-ended1855=== CONT TestParseSingleRange/start_far_past_EOF1856=== CONT TestParseSingleRange/start_past_EOF1857=== CONT TestParseSingleRange/single_byte1858=== CONT TestParseSingleRange/suffix_exceeds_size1859=== CONT TestParseSingleRange/suffix1860=== CONT TestParseSingleRange/malformed_both_empty1861=== CONT TestParseSingleRange/closed1862=== CONT TestParseSingleRange/malformed_end_before_start1863=== CONT TestParseSingleRange/end_clamped_to_size1864=== CONT TestParseSingleRange/multi-range_ignored1865=== CONT TestParseSingleRange/malformed_no_dash1866=== CONT TestParseSingleRange/unknown_unit1867--- PASS: TestParseSingleRange (0.00s)1868 --- PASS: TestParseSingleRange/none (0.00s)1869 --- PASS: TestParseSingleRange/open-ended (0.00s)1870 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1871 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1872 --- PASS: TestParseSingleRange/single_byte (0.00s)1873 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1874 --- PASS: TestParseSingleRange/suffix (0.00s)1875 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1876 --- PASS: TestParseSingleRange/closed (0.00s)1877 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1878 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1879 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1880 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1881 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1882=== CONT TestCacheConfigHandler/full_config,_no_issuer1883=== CONT TestCacheConfigHandler/no_signing_keys1884=== CONT TestCacheConfigHandler/no_cache_url_configured1885=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1886--- PASS: TestCacheConfigHandler (0.00s)1887 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1888 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1889 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1890 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1891=== CONT TestIsValidCachePath/narinfo1892=== CONT TestIsValidCachePath/leading_slash1893=== CONT TestIsValidCachePath/empty1894=== CONT TestIsValidCachePath/wrong_extension1895=== CONT TestIsValidCachePath/random_path1896=== CONT TestIsValidCachePath/invalid_char_u1897=== CONT TestIsValidCachePath/invalid_char_e1898=== CONT TestIsValidCachePath/traversal_in_middle1899=== CONT TestIsValidCachePath/traversal_parent1900=== CONT TestIsValidCachePath/index.html1901=== CONT TestIsValidCachePath/nix-cache-info1902=== CONT TestIsValidCachePath/realisation1903=== CONT TestIsValidCachePath/log1904=== CONT TestIsValidCachePath/ls1905=== CONT TestIsValidCachePath/nar_uncompressed1906=== CONT TestIsValidCachePath/nar_bz21907=== CONT TestIsValidCachePath/nar_xz1908=== CONT TestIsValidCachePath/nar_zst1909=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1910=== CONT TestIsValidCachePath/short_hash1911--- PASS: TestIsValidCachePath (0.00s)1912 --- PASS: TestIsValidCachePath/narinfo (0.00s)1913 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1914 --- PASS: TestIsValidCachePath/empty (0.00s)1915 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1916 --- PASS: TestIsValidCachePath/random_path (0.00s)1917 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1918 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1919 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1920 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1921 --- PASS: TestIsValidCachePath/index.html (0.00s)1922 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1923 --- PASS: TestIsValidCachePath/realisation (0.00s)1924 --- PASS: TestIsValidCachePath/log (0.00s)1925 --- PASS: TestIsValidCachePath/ls (0.00s)1926 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1927 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1928 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1929 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1930 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1931 --- PASS: TestIsValidCachePath/short_hash (0.00s)1932=== CONT TestServerTLSConfig/no_client_CA1933=== CONT TestServerTLSConfig/not_a_PEM_file1934=== CONT TestServerTLSConfig/missing_CA_file1935--- PASS: TestServerTLSConfig (0.00s)1936 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1937 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1938 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1939=== CONT TestProxyWriteTimeout/narinfo1940=== CONT TestProxyWriteTimeout/10_GiB_nar1941=== CONT TestProxyWriteTimeout/unknown_size1942=== CONT TestProxyWriteTimeout/1_GiB_nar1943=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1944--- PASS: TestProxyWriteTimeout (0.00s)1945 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1946 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1947 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1948 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)19492026/09/07 10:03:53 INFO Received uploads request method=POST path=/1950=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19512026/09/07 10:03:53 INFO Received complete multipart upload request method=POST path=/1952=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19532026/09/07 10:03:53 INFO Received uploads request method=POST path=/1954=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19552026/09/07 10:03:53 INFO Received request for more parts method=POST path=/1956--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1957 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1958 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1959 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1960 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1961=== CONT TestIsValidUploadKey/narinfo1962=== CONT TestIsValidUploadKey/realisation_plus_in_output1963=== CONT TestIsValidUploadKey/unknown_type1964=== CONT TestIsValidUploadKey/empty_key1965=== CONT TestIsValidUploadKey/absolute1966=== CONT TestIsValidUploadKey/traversal_nar1967=== CONT TestIsValidUploadKey/traversal1968=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1969=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1970=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1971=== CONT TestIsValidUploadKey/index.html1972=== CONT TestIsValidUploadKey/nix-cache-info1973=== CONT TestIsValidUploadKey/build_log_home-manager_file1974=== CONT TestIsValidUploadKey/nar_plain1975=== CONT TestIsValidUploadKey/realisation1976=== CONT TestIsValidUploadKey/build_log1977=== CONT TestIsValidUploadKey/build_log_equals1978=== CONT TestIsValidUploadKey/listing1979=== CONT TestIsValidUploadKey/build_log_question_mark1980=== CONT TestIsValidUploadKey/build_log_plus_in_name1981=== CONT TestIsValidUploadKey/nar_xz1982=== CONT TestIsValidUploadKey/nar_zst1983--- PASS: TestIsValidUploadKey (0.00s)1984 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1985 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1986 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1987 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1988 --- PASS: TestIsValidUploadKey/absolute (0.00s)1989 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1990 --- PASS: TestIsValidUploadKey/traversal (0.00s)1991 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1992 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1993 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1994 --- PASS: TestIsValidUploadKey/index.html (0.00s)1995 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1996 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1997 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1998 --- PASS: TestIsValidUploadKey/realisation (0.00s)1999 --- PASS: TestIsValidUploadKey/build_log (0.00s)2000 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2001 --- PASS: TestIsValidUploadKey/listing (0.00s)2002 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2003 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2004 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2005 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2006=== RUN TestService_RequireScope_OIDC/builder_may_write2007=== PAUSE TestService_RequireScope_OIDC/builder_may_write2008=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2009=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2010=== RUN TestService_RequireScope_OIDC/ops_may_admin2011=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2012=== RUN TestService_RequireScope_OIDC/ops_may_not_write2013=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2014=== RUN TestService_RequireScope_OIDC/reader_may_not_write2015=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2016=== RUN TestService_RequireScope_OIDC/static_token_may_admin2017=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2018=== RUN TestService_RequireScope_OIDC/static_token_may_write2019=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2020=== RUN TestService_RequireScope_OIDC/reader_may_read2021=== PAUSE TestService_RequireScope_OIDC/reader_may_read2022=== RUN TestService_RequireScope_OIDC/writer_implies_read2023=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2024=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2025=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2026=== CONT TestService_RequireScope_OIDC/builder_may_write2027=== CONT TestService_RequireScope_OIDC/static_token_may_admin2028=== CONT TestService_RequireScope_OIDC/ops_may_not_write2029=== CONT TestService_RequireScope_OIDC/reader_may_not_write20302026/09/07 10:03:53 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=370.779038ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20312026/09/07 10:03:53 INFO OIDC auth successful provider=test scopes=[write]20322026/09/07 10:03:53 INFO OIDC auth successful provider=test scopes=[admin]2033=== CONT TestService_RequireScope_OIDC/writer_implies_read2034=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read20352026/09/07 10:03:53 INFO OIDC auth successful provider=test scopes=[read]2036=== CONT TestService_RequireScope_OIDC/reader_may_read20372026/09/07 10:03:53 INFO OIDC auth successful provider=test scopes=[write]2038=== CONT TestService_RequireScope_OIDC/ops_may_admin2039=== CONT TestService_RequireScope_OIDC/builder_may_not_admin20402026/09/07 10:03:53 INFO OIDC auth successful provider=test scopes=[read]2041=== CONT TestService_RequireScope_OIDC/static_token_may_write20422026/09/07 10:03:53 INFO OIDC auth successful provider=test scopes=[write]20432026/09/07 10:03:53 INFO OIDC auth successful provider=test scopes=[admin]2044--- PASS: TestService_RequireScope_OIDC (1.28s)2045 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2046 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.01s)2047 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.01s)2048 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2049 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.01s)2050 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2051 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2052 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2053 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2054 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2055--- PASS: TestReadProxyNarinfo (1.27s)20562026/09/07 10:03:53 INFO Received uploads request method=POST path=/api/pending_closures20572026/09/07 10:03:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2058--- PASS: TestObjectStatsTrigger (1.26s)2059=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2060=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2061=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2062=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2063=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2064=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2065=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2066=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2067=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2068=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2069=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured20702026/09/07 10:03:53 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2071=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20722026/09/07 10:03:53 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=ZWQxYjI2ZDktYjZmOC00YjRkLWFjN2UtOGM3NTFhZDBkNWJjLjM4ODRkYTNjLTZhMGUtNGIwNi1iNWMyLTllNTE2YWY4YWM3MXgxNzg4Nzc1NDMyOTM3NTY2MjAy parts=1020732026/09/07 10:03:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20742026/09/07 10:03:53 INFO Signed narinfos id=1 count=120752026/09/07 10:03:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20762026/09/07 10:03:53 INFO Received uploads request method=POST path=/api/pending_closures20772026/09/07 10:03:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20782026/09/07 10:03:53 INFO Signed narinfos id=2 count=120792026/09/07 10:03:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20802026/09/07 10:03:53 INFO Completed upload id=220812026/09/07 10:03:53 INFO OIDC auth successful provider=test scopes=[write]20822026/09/07 10:03:53 WARN Authentication failed token_preview=eyJhbGciOi...P39pEiwOBg token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]20832026/09/07 10:03:53 WARN claim: cannot clear write deadline error="feature not supported"2084--- PASS: TestService_AuthMiddleware_OIDC (0.94s)2085 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2086 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2087 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2088 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2089--- PASS: TestClaim_BuildWaitComplete (2.88s)20902026-09-07 10:03:53.701 UTC [1500] LOG: could not send data to client: Broken pipe20912026-09-07 10:03:53.701 UTC [1500] FATAL: connection to client lost2092--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.93s)20932026/09/07 10:03:53 WARN mTLS auth: subject not in bound subjects subject="CN=reader"20942026/09/07 10:03:53 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2095--- PASS: TestService_NativeMTLS (0.95s)20962026/09/07 10:03:53 INFO Received cleanup request method=DELETE path=/api/pending_closures20972026/09/07 10:03:53 INFO Aborted multipart uploads count=12098--- PASS: TestMultipartCleanup (1.29s)20992026/09/07 10:03:53 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=1000 objects_failed=02100=== NAME TestOrphanedObjectsGC2101 orphaned_objects_gc_test.go:290: GC Test Summary:2102 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2103 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2104 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2105 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2106 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2107--- PASS: TestOrphanedObjectsGC (1.63s)21082026/09/07 10:03:53 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=834.125527ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21092026/09/07 10:03:53 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21102026/09/07 10:03:53 WARN mTLS auth: bound subjects configured but subject DN unavailable21112026/09/07 10:03:53 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2112--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.14s)2113--- PASS: TestService_ReadAuthMiddleware (1.13s)2114--- PASS: TestService_healthCheckHandler (1.10s)21152026/09/07 10:03:54 WARN readiness check failed error="closed pool"2116--- PASS: TestService_readinessHandler (1.10s)21172026/09/07 10:03:54 INFO Received uploads request method=POST path=/api/pending_closures2118=== NAME TestNARDeduplicationMetadataUploadBug2119 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1756551151/001/store/1lb3czyk79qvrv3ymnf7zyspc3lfjm92-file1.txt21202026/09/07 10:03:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21212026/09/07 10:03:54 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21222026/09/07 10:03:54 INFO Received uploads request method=POST path=/api/pending_closures21232026/09/07 10:03:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21242026/09/07 10:03:54 INFO Uploading 1lb3czyk79qvrv3ymnf7zyspc3lfjm92-file1.txt (160B)21252026/09/07 10:03:54 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21262026/09/07 10:03:54 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"21272026/09/07 10:03:54 WARN Failed to register uploaded object key=1lb3czyk79qvrv3ymnf7zyspc3lfjm92.ls error="server returned 404: 404 page not found\n"21282026/09/07 10:03:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21292026/09/07 10:03:54 INFO Signed narinfos id=1 count=121302026/09/07 10:03:54 INFO Uploading 1 narinfos21312026/09/07 10:03:54 WARN Failed to register uploaded object key=1lb3czyk79qvrv3ymnf7zyspc3lfjm92.narinfo error="server returned 404: 404 page not found\n"21322026/09/07 10:03:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21332026/09/07 10:03:54 INFO Completed upload id=121342026/09/07 10:03:54 INFO Upload complete. (108ms)2135 metadata_upload_test.go:54: Retrieved narinfo from S3:2136 StorePath: /build/TestNARDeduplicationMetadataUploadBug1756551151/001/store/1lb3czyk79qvrv3ymnf7zyspc3lfjm92-file1.txt2137 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2138 Compression: zstd2139 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2140 NarSize: 1602141 References: 2142 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2143 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2144 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2145 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}21462026/09/07 10:03:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2147 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1756551151/001/store/3zp6s451qmshh607s2j2pw5yaxs57zqp-file2.txt21482026/09/07 10:03:54 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21492026/09/07 10:03:54 INFO Received uploads request method=POST path=/api/pending_closures21502026/09/07 10:03:54 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21512026/09/07 10:03:54 WARN Failed to register uploaded object key=3zp6s451qmshh607s2j2pw5yaxs57zqp.ls error="server returned 404: 404 page not found\n"21522026/09/07 10:03:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21532026/09/07 10:03:54 INFO Signed narinfos id=2 count=121542026/09/07 10:03:54 INFO Uploading 1 narinfos21552026/09/07 10:03:54 WARN Failed to register uploaded object key=3zp6s451qmshh607s2j2pw5yaxs57zqp.narinfo error="server returned 404: 404 page not found\n"21562026/09/07 10:03:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21572026/09/07 10:03:54 INFO Completed upload id=221582026/09/07 10:03:54 INFO Upload complete. (102ms)2159 metadata_upload_test.go:76: Retrieved narinfo from S3:2160 StorePath: /build/TestNARDeduplicationMetadataUploadBug1756551151/001/store/3zp6s451qmshh607s2j2pw5yaxs57zqp-file2.txt2161 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2162 Compression: zstd2163 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2164 NarSize: 1602165 References: 2166 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2167 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2168 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2169 {"version":1,"root":{"type":"regular","size":44}}2170--- PASS: TestNARDeduplicationMetadataUploadBug (1.44s)21712026/09/07 10:03:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=021722026/09/07 10:03:54 INFO Vacuumed table table=pending_closures21732026/09/07 10:03:54 INFO Vacuumed table table=pending_objects21742026/09/07 10:03:54 INFO Vacuumed table table=multipart_uploads21752026/09/07 10:03:54 INFO Vacuumed table table=closures21762026/09/07 10:03:54 INFO Vacuumed table table=objects21772026/09/07 10:03:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.683517669s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21782026/09/07 10:03:54 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=1000 objects_failed=02179--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)2180 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.11s)2181 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.12s)2182 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.63s)21832026/09/07 10:03:55 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=021842026/09/07 10:03:55 INFO Vacuumed table table=pending_closures21852026/09/07 10:03:55 INFO Vacuumed table table=pending_objects21862026/09/07 10:03:55 INFO Vacuumed table table=multipart_uploads21872026/09/07 10:03:55 INFO Vacuumed table table=closures21882026/09/07 10:03:55 INFO Vacuumed table table=objects2189=== NAME TestOrphanedObjectsGCStressTest2190 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2191 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2192 orphaned_objects_gc_test.go:509: Stress test completed successfully:2193 orphaned_objects_gc_test.go:510: - Active objects preserved: 202194 orphaned_objects_gc_test.go:511: - Objects deleted: 2102195 orphaned_objects_gc_test.go:512: - Total GC'd: 2102196--- PASS: TestOrphanedObjectsGCStressTest (3.79s)21972026/09/07 10:03:55 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02198=== NAME TestClientIntegration2199 client_integration_test.go:304: Objects in database after GC:2200 client_integration_test.go:304: Successfully deleted all objects with GC --force2201--- PASS: TestClientIntegration (7.36s)22022026/09/07 10:03:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22032026/09/07 10:03:56 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22042026/09/07 10:03:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.757181ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22052026/09/07 10:03:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=417.337629ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22062026/09/07 10:03:56 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02207=== NAME TestPinProtectsFromGC2208 client_integration_test.go:711: Pin successfully protected closure from garbage collection2209--- PASS: TestPinProtectsFromGC (8.51s)22102026/09/07 10:03:57 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=738.976817ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22112026/09/07 10:03:57 WARN Rate limiter enabled after throttle name=s3-test rate=522122026/09/07 10:03:57 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2213=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2214 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102215 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002216--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.53s)22172026/09/07 10:03:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.591696396s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2218--- PASS: TestClientErrorHandling (0.01s)2219 --- PASS: TestClientErrorHandling/InvalidStorePath (1.10s)2220 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.93s)2221 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.39s)2222PASS22232026-09-07 10:03:59.951 UTC [110] LOG: received smart shutdown request22242026-09-07 10:03:59.958 UTC [110] LOG: background worker "logical replication launcher" (PID 120) exited with exit code 122252026-09-07 10:03:59.974 UTC [115] LOG: shutting down22262026-09-07 10:03:59.974 UTC [115] LOG: checkpoint starting: shutdown immediate22272026-09-07 10:04:01.241 UTC [115] LOG: checkpoint complete: wrote 11806 buffers (72.1%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 17 recycled; write=0.285 s, sync=0.968 s, total=1.268 s; sync files=21000, longest=0.011 s, average=0.001 s; distance=282889 kB, estimate=282889 kB; lsn=0/12BA8348, redo lsn=0/12BA834822282026-09-07 10:04:01.351 UTC [110] LOG: database system is shut down2229Running OIDC tests...2230=== RUN TestGlobMatch2231=== PAUSE TestGlobMatch2232=== RUN TestAudienceForIssuer2233=== PAUSE TestAudienceForIssuer2234=== RUN TestValidateToken_ValidToken2235=== PAUSE TestValidateToken_ValidToken2236=== RUN TestValidateToken_WrongAudience2237=== PAUSE TestValidateToken_WrongAudience2238=== RUN TestValidateToken_Expired2239=== PAUSE TestValidateToken_Expired2240=== RUN TestValidateToken_BoundClaimsMismatch2241=== PAUSE TestValidateToken_BoundClaimsMismatch2242=== RUN TestValidateToken_BoundSubjectMismatch2243=== PAUSE TestValidateToken_BoundSubjectMismatch2244=== RUN TestValidateToken_MultipleProviders2245=== PAUSE TestValidateToken_MultipleProviders2246=== RUN TestValidateToken_NoMatchingProvider2247=== PAUSE TestValidateToken_NoMatchingProvider2248=== RUN TestValidateToken_KubernetesServiceAccount2249=== PAUSE TestValidateToken_KubernetesServiceAccount2250=== RUN TestNewValidator_KubernetesRequiresCA2251=== PAUSE TestNewValidator_KubernetesRequiresCA2252=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2253=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2254=== RUN TestScopes_LegacyProviderDefaultsToWrite2255=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2256=== RUN TestScopes_Rules2257=== PAUSE TestScopes_Rules2258=== RUN TestScopes_ConfigValidation2259=== PAUSE TestScopes_ConfigValidation2260=== CONT TestGlobMatch2261=== CONT TestValidateToken_NoMatchingProvider2262=== CONT TestNewValidator_KubernetesRequiresCA2263=== RUN TestGlobMatch/foo_foo2264=== PAUSE TestGlobMatch/foo_foo2265=== CONT TestValidateToken_MultipleProviders2266=== CONT TestValidateToken_BoundSubjectMismatch2267=== CONT TestValidateToken_BoundClaimsMismatch2268=== CONT TestValidateToken_Expired2269=== CONT TestValidateToken_WrongAudience2270=== CONT TestValidateToken_ValidToken2271=== CONT TestAudienceForIssuer2272--- PASS: TestAudienceForIssuer (0.00s)2273=== CONT TestScopes_ConfigValidation2274=== CONT TestValidateToken_KubernetesServiceAccount2275=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2276=== CONT TestScopes_Rules2277=== CONT TestScopes_LegacyProviderDefaultsToWrite2278=== RUN TestGlobMatch/foo_bar2279=== PAUSE TestGlobMatch/foo_bar2280=== RUN TestGlobMatch/*_2281=== PAUSE TestGlobMatch/*_2282=== RUN TestGlobMatch/*_anything2283=== PAUSE TestGlobMatch/*_anything2284=== RUN TestGlobMatch/foo*_foo2285=== PAUSE TestGlobMatch/foo*_foo2286=== RUN TestGlobMatch/foo*_foobar2287=== PAUSE TestGlobMatch/foo*_foobar2288=== RUN TestGlobMatch/foo*_bar2289=== PAUSE TestGlobMatch/foo*_bar2290=== RUN TestGlobMatch/*bar_bar2291=== PAUSE TestGlobMatch/*bar_bar2292=== RUN TestGlobMatch/*bar_foobar2293=== PAUSE TestGlobMatch/*bar_foobar2294=== RUN TestGlobMatch/*bar_foo2295=== PAUSE TestGlobMatch/*bar_foo2296=== RUN TestGlobMatch/foo*bar_foobar2297=== PAUSE TestGlobMatch/foo*bar_foobar2298=== RUN TestGlobMatch/foo*bar_foo123bar2299=== PAUSE TestGlobMatch/foo*bar_foo123bar2300=== RUN TestGlobMatch/foo*bar_foobarbaz2301=== PAUSE TestGlobMatch/foo*bar_foobarbaz2302=== RUN TestGlobMatch/*/*_foo/bar2303=== PAUSE TestGlobMatch/*/*_foo/bar2304=== RUN TestGlobMatch/*/*_foo2305=== PAUSE TestGlobMatch/*/*_foo2306=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2307=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2308=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.023092026/09/07 10:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38071/oidc2310=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.023112026/09/07 10:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35311/oidc2312=== RUN TestGlobMatch/refs/*/main_refs/heads/main23132026/09/07 10:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36079/oidc2314=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main23152026/09/07 10:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35709/oidc2316=== RUN TestGlobMatch/fo?_foo2317--- PASS: TestScopes_ConfigValidation (0.01s)23182026/09/07 10:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45317/oidc2319=== PAUSE TestGlobMatch/fo?_foo2320=== RUN TestGlobMatch/fo?_fo23212026/09/07 10:04:02 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42947/oidc2322=== PAUSE TestGlobMatch/fo?_fo2323=== RUN TestGlobMatch/fo?_fooo23242026/09/07 10:04:02 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39795/oidc2325=== PAUSE TestGlobMatch/fo?_fooo2326=== RUN TestGlobMatch/?oo_foo2327=== PAUSE TestGlobMatch/?oo_foo2328=== RUN TestGlobMatch/?oo_boo2329=== PAUSE TestGlobMatch/?oo_boo2330=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2331=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2332=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2333=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2334=== CONT TestGlobMatch/foo_foo23352026/09/07 10:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38229/oidc2336=== CONT TestGlobMatch/*/*_foo/bar2337=== CONT TestGlobMatch/foo*_bar2338=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.023392026/09/07 10:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35155/oidc2340=== CONT TestGlobMatch/foo*bar_foobarbaz2341=== CONT TestGlobMatch/fo?_foo2342=== CONT TestGlobMatch/foo*_foo2343=== CONT TestGlobMatch/fo?_fo2344=== CONT TestGlobMatch/*_anything2345=== CONT TestGlobMatch/?oo_foo2346=== CONT TestGlobMatch/foo*bar_foo123bar2347=== CONT TestGlobMatch/*_2348=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2349=== CONT TestGlobMatch/*/*_foo2350=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2351=== CONT TestGlobMatch/foo*bar_foobar2352=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2353=== CONT TestGlobMatch/*bar_foo23542026/09/07 10:04:02 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:44259/oidc2355=== CONT TestGlobMatch/?oo_boo2356=== CONT TestGlobMatch/*bar_foobar2357=== CONT TestGlobMatch/fo?_fooo2358=== CONT TestGlobMatch/*bar_bar2359=== CONT TestGlobMatch/foo*_foobar2360=== CONT TestGlobMatch/refs/*/main_refs/heads/main2361=== CONT TestGlobMatch/foo_bar2362--- PASS: TestGlobMatch (0.01s)2363 --- PASS: TestGlobMatch/foo_foo (0.00s)2364 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2365 --- PASS: TestGlobMatch/foo*_bar (0.00s)2366 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2367 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2368 --- PASS: TestGlobMatch/fo?_foo (0.00s)2369 --- PASS: TestGlobMatch/foo*_foo (0.00s)2370 --- PASS: TestGlobMatch/fo?_fo (0.00s)2371 --- PASS: TestGlobMatch/*_anything (0.00s)2372 --- PASS: TestGlobMatch/?oo_foo (0.00s)2373 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2374 --- PASS: TestGlobMatch/*_ (0.00s)2375 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2376 --- PASS: TestGlobMatch/*/*_foo (0.00s)2377 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2378 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2379 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2380 --- PASS: TestGlobMatch/*bar_foo (0.00s)2381 --- PASS: TestGlobMatch/?oo_boo (0.00s)2382 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2383 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2384 --- PASS: TestGlobMatch/*bar_bar (0.00s)2385 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2386 --- PASS: TestGlobMatch/foo_bar (0.00s)2387 --- PASS: TestGlobMatch/foo*_foobar (0.00s)23882026/09/07 10:04:02 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232389--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)2390--- PASS: TestValidateToken_Expired (0.01s)2391--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2392--- PASS: TestValidateToken_ValidToken (0.01s)2393--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2394--- PASS: TestValidateToken_WrongAudience (0.02s)2395--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)23962026/09/07 10:04:02 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:397572397--- PASS: TestValidateToken_MultipleProviders (0.02s)2398--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)23992026/09/07 10:04:02 http: TLS handshake error from 127.0.0.1:59666: remote error: tls: bad certificate2400--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)2401--- PASS: TestScopes_Rules (0.02s)2402--- PASS: TestValidateToken_KubernetesServiceAccount (0.03s)2403PASS2404Running hook tests...2405=== RUN TestSendPathsEmpty2406=== PAUSE TestSendPathsEmpty2407=== RUN TestQueueEnqueueAndFetch2408=== PAUSE TestQueueEnqueueAndFetch2409=== RUN TestQueueDeduplication2410=== PAUSE TestQueueDeduplication2411=== RUN TestQueueRemove2412=== PAUSE TestQueueRemove2413=== RUN TestQueueFetchBatchLimit2414=== PAUSE TestQueueFetchBatchLimit2415=== RUN TestQueueRetryMovesToBack2416=== PAUSE TestQueueRetryMovesToBack2417=== RUN TestQueueFetchRemoveLifecycle2418=== PAUSE TestQueueFetchRemoveLifecycle2419=== RUN TestQueueConcurrentWriters2420=== PAUSE TestQueueConcurrentWriters2421=== RUN TestQueueRemoveLargeClosure2422=== PAUSE TestQueueRemoveLargeClosure2423=== RUN TestServerClientIntegration2424=== PAUSE TestServerClientIntegration2425=== RUN TestServerQueueError2426=== PAUSE TestServerQueueError2427=== RUN TestGetListenerSocketActivation2428 server_test.go:214: === RUN TestGetListenerSocketActivation2429 --- PASS: TestGetListenerSocketActivation (0.00s)2430 PASS2431 2432--- PASS: TestGetListenerSocketActivation (0.01s)2433=== RUN TestServerWait2434=== PAUSE TestServerWait2435=== RUN TestDrainIsolatesPoisonPath2436=== PAUSE TestDrainIsolatesPoisonPath2437=== RUN TestRunNotBlockedByPoisonHead2438=== PAUSE TestRunNotBlockedByPoisonHead2439=== RUN TestDrainGivesUpWhenServerDown2440=== PAUSE TestDrainGivesUpWhenServerDown2441=== RUN TestFailedPathPrunedByLaterClosure2442=== PAUSE TestFailedPathPrunedByLaterClosure2443=== RUN TestWorkerUploadsAndRemoves2444=== PAUSE TestWorkerUploadsAndRemoves2445=== RUN TestWorkerSkipsGCdPaths2446=== PAUSE TestWorkerSkipsGCdPaths2447=== RUN TestWorkerPrunesClosureDeps2448=== PAUSE TestWorkerPrunesClosureDeps2449=== RUN TestDrainTimeout2450=== PAUSE TestDrainTimeout2451=== CONT TestSendPathsEmpty2452=== CONT TestServerQueueError2453=== CONT TestQueueConcurrentWriters2454--- PASS: TestSendPathsEmpty (0.00s)2455=== CONT TestQueueFetchBatchLimit2456=== CONT TestQueueRemove2457=== CONT TestQueueDeduplication2458=== CONT TestQueueRetryMovesToBack2459=== CONT TestQueueEnqueueAndFetch2460=== CONT TestServerClientIntegration2461=== CONT TestFailedPathPrunedByLaterClosure2462=== CONT TestQueueRemoveLargeClosure2463=== CONT TestDrainTimeout2464=== CONT TestWorkerPrunesClosureDeps2465=== CONT TestQueueFetchRemoveLifecycle2466=== CONT TestWorkerUploadsAndRemoves2467=== CONT TestRunNotBlockedByPoisonHead2468=== CONT TestDrainGivesUpWhenServerDown2469=== CONT TestDrainIsolatesPoisonPath24702026/09/07 10:04:02 ERROR Hook request failed error="permission denied" wait=false count=12471=== CONT TestServerWait2472=== CONT TestWorkerSkipsGCdPaths2473--- PASS: TestServerClientIntegration (0.00s)2474--- PASS: TestServerQueueError (0.00s)2475--- PASS: TestServerWait (0.00s)24762026/09/07 10:04:02 INFO Uploading batch count=224772026/09/07 10:04:02 INFO Uploading batch count=124782026/09/07 10:04:02 ERROR Upload failed error="upload failed" count=124792026/09/07 10:04:02 INFO Upload queue status pending=22480--- PASS: TestQueueFetchBatchLimit (0.02s)24812026/09/07 10:04:02 INFO Upload queue status pending=324822026/09/07 10:04:02 INFO Uploading batch count=224832026/09/07 10:04:02 INFO Uploading batch count=124842026/09/07 10:04:02 ERROR Upload failed error="upload failed" count=124852026/09/07 10:04:02 INFO Upload queue status pending=224862026/09/07 10:04:02 INFO Uploading batch count=12487--- PASS: TestQueueRetryMovesToBack (0.02s)2488--- PASS: TestQueueFetchRemoveLifecycle (0.02s)24892026/09/07 10:04:02 INFO Uploading batch count=124902026/09/07 10:04:02 INFO Uploading batch count=424912026/09/07 10:04:02 ERROR Upload failed error="upload failed" count=42492--- PASS: TestQueueDeduplication (0.02s)24932026/09/07 10:04:02 INFO Uploading batch count=224942026/09/07 10:04:02 ERROR Upload failed error="upload failed" count=224952026/09/07 10:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3033580377/002/a2496--- PASS: TestQueueRemove (0.02s)24972026/09/07 10:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1531159671/002/bbb24982026/09/07 10:04:02 INFO Upload queue status pending=224992026/09/07 10:04:02 INFO Uploading batch count=125002026/09/07 10:04:02 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3241311281/002/nonexistent25012026/09/07 10:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3033580377/002/b2502--- PASS: TestQueueEnqueueAndFetch (0.02s)25032026/09/07 10:04:02 INFO Uploading batch count=225042026/09/07 10:04:02 ERROR Upload failed error="upload failed" count=225052026/09/07 10:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3033580377/002/c25062026/09/07 10:04:02 INFO Uploading batch count=125072026/09/07 10:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3033580377/002/d2508--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25092026/09/07 10:04:02 INFO Uploading batch count=125102026/09/07 10:04:02 ERROR Upload failed error="upload failed" count=125112026/09/07 10:04:02 INFO Uploading batch count=125122026/09/07 10:04:02 ERROR Upload failed error="upload failed" count=125132026/09/07 10:04:02 INFO Uploading batch count=225142026/09/07 10:04:02 ERROR Upload failed error="upload failed" count=225152026/09/07 10:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3033580377/002/e25162026/09/07 10:04:02 INFO Uploading batch count=125172026/09/07 10:04:02 ERROR Upload failed error="upload failed" count=125182026/09/07 10:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3033580377/002/f25192026/09/07 10:04:02 ERROR Drain finished with paths left in queue remaining=125202026/09/07 10:04:02 ERROR Drain finished with paths left in queue remaining=102521--- PASS: TestDrainIsolatesPoisonPath (0.03s)2522--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2523--- PASS: TestWorkerPrunesClosureDeps (0.04s)2524--- PASS: TestWorkerUploadsAndRemoves (0.04s)2525--- PASS: TestWorkerSkipsGCdPaths (0.04s)25262026/09/07 10:04:02 ERROR Upload failed error="context deadline exceeded" count=225272026/09/07 10:04:02 ERROR Drain finished with paths left in queue remaining=42528--- PASS: TestDrainTimeout (0.22s)2529--- PASS: TestQueueConcurrentWriters (0.28s)2530--- PASS: TestQueueRemoveLargeClosure (0.34s)25312026/09/07 10:04:03 INFO Uploading batch count=125322026/09/07 10:04:03 INFO Uploading batch count=125332026/09/07 10:04:03 INFO Uploading batch count=125342026/09/07 10:04:03 ERROR Upload failed error="upload failed" count=125352026/09/07 10:04:03 INFO Uploading batch count=125362026/09/07 10:04:03 ERROR Upload failed error="upload failed" count=125372026/09/07 10:04:03 INFO Uploading batch count=125382026/09/07 10:04:03 ERROR Upload failed error="upload failed" count=125392026/09/07 10:04:03 INFO Uploading batch count=125402026/09/07 10:04:03 ERROR Upload failed error="upload failed" count=125412026/09/07 10:04:03 ERROR Drain finished with paths left in queue remaining=12542--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2543PASS