niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #194
· 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 TestDumpPathCaseHackMatchesNix14--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)15=== RUN TestDumpPathCaseHackCollision16--- PASS: TestDumpPathCaseHackCollision (0.00s)17=== RUN TestDumpPathMatchesNix18=== PAUSE TestDumpPathMatchesNix19=== RUN TestDumpPathSingleFile20=== PAUSE TestDumpPathSingleFile21=== RUN TestDumpPathWriterError22=== PAUSE TestDumpPathWriterError23=== RUN TestEncodeNixBase3224=== PAUSE TestEncodeNixBase3225=== RUN TestEncodeNixBase32WithRealHash26=== PAUSE TestEncodeNixBase32WithRealHash27=== RUN TestConvertHashToNix3228=== PAUSE TestConvertHashToNix3229=== RUN TestGetStorePathHash30=== PAUSE TestGetStorePathHash31=== RUN TestPathInfoHashCompatibility32=== PAUSE TestPathInfoHashCompatibility33=== RUN TestParsePathInfoJSON34=== PAUSE TestParsePathInfoJSON35=== RUN TestParsePathInfoJSONMultiplePaths36=== PAUSE TestParsePathInfoJSONMultiplePaths37=== RUN TestPathInfoCACompatibility38=== PAUSE TestPathInfoCACompatibility39=== RUN TestRateLimiterFeedback40=== PAUSE TestRateLimiterFeedback41=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess42=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess43=== RUN TestResolveStorePath44=== PAUSE TestResolveStorePath45=== RUN TestDoWithRetry_BodyReplayedViaGetBody46=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody47=== RUN TestShellSplit48=== PAUSE TestShellSplit49=== RUN TestShellSplitErrors50=== PAUSE TestShellSplitErrors51=== RUN TestStreamPushReportsEveryPath52=== PAUSE TestStreamPushReportsEveryPath53=== RUN TestStreamPushBatchesUnderLoad54=== PAUSE TestStreamPushBatchesUnderLoad55=== RUN TestStreamPushIsolatesFailures56=== PAUSE TestStreamPushIsolatesFailures57=== RUN TestStreamPushGivesUpOnDeadServer58=== PAUSE TestStreamPushGivesUpOnDeadServer59=== RUN TestSetClientTLS60=== PAUSE TestSetClientTLS61=== RUN TestSetClientTLSDoesNotMutateDefaultTransport62=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport63=== RUN TestSetClientTLSErrors64=== PAUSE TestSetClientTLSErrors65=== RUN TestStaticToken66=== PAUSE TestStaticToken67=== RUN TestFileTokenReadsAndCaches68=== PAUSE TestFileTokenReadsAndCaches69=== RUN TestFileTokenMissing70=== PAUSE TestFileTokenMissing71=== RUN TestFileTokenEmpty72=== PAUSE TestFileTokenEmpty73=== RUN TestScriptTokenNoExpiryRerunsEveryCall74=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall75=== RUN TestScriptTokenCachesUntilRefresh76=== PAUSE TestScriptTokenCachesUntilRefresh77=== RUN TestScriptTokenEmptyToken78=== PAUSE TestScriptTokenEmptyToken79=== RUN TestScriptTokenBadJSON80=== PAUSE TestScriptTokenBadJSON81=== RUN TestScriptTokenScriptFails82=== PAUSE TestScriptTokenScriptFails83=== RUN TestScriptTokenEmptyCommand84=== PAUSE TestScriptTokenEmptyCommand85=== CONT TestDoServerRequestAttachesToken86=== CONT TestDoWithRetry_BodyReplayedViaGetBody87=== CONT TestStaticToken88=== CONT TestScriptTokenEmptyCommand89=== CONT TestConvertHashToNix3290=== CONT TestDumpPathWriterError91=== RUN TestConvertHashToNix32/SRI_format_to_Nix3292=== CONT TestResolveStorePath93=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess94=== CONT TestRateLimiterFeedback95=== CONT TestPathInfoCACompatibility96=== CONT TestParsePathInfoJSONMultiplePaths97=== CONT TestParsePathInfoJSON98=== CONT TestPathInfoHashCompatibility99=== CONT TestGetStorePathHash100=== CONT TestScriptTokenCachesUntilRefresh101=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths102=== CONT TestScriptTokenScriptFails103=== CONT TestScriptTokenBadJSON104=== CONT TestScriptTokenEmptyToken105=== CONT TestStreamPushIsolatesFailures106=== CONT TestSetClientTLSErrors107=== CONT TestSetClientTLSDoesNotMutateDefaultTransport108=== CONT TestSetClientTLS109=== CONT TestStreamPushGivesUpOnDeadServer110=== CONT TestDumpPathMatchesNix111=== CONT TestEncodeNixBase32WithRealHash112--- PASS: TestStaticToken (0.00s)113=== CONT TestEncodeNixBase32114=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32115=== RUN TestPathInfoCACompatibility/null_ca_field116=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)117=== RUN TestParsePathInfoJSON/Nix_format118=== RUN TestRateLimiterFeedback/429_enables_limiter119=== RUN TestGetStorePathHash/valid_store_path120--- PASS: TestScriptTokenEmptyCommand (0.00s)121=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths122=== RUN TestConvertHashToNix32/already_Nix32_format123--- PASS: TestResolveStorePath (0.00s)124=== CONT TestDumpPathSingleFile125=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)126=== PAUSE TestRateLimiterFeedback/429_enables_limiter127=== PAUSE TestGetStorePathHash/valid_store_path128=== RUN TestRateLimiterFeedback/503_enables_limiter129=== PAUSE TestRateLimiterFeedback/503_enables_limiter130=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter131=== RUN TestGetStorePathHash/basename_without_hyphen_should_error132=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error1332026/09/10 17:36:36 WARN Rate limiter enabled after throttle name=server-test rate=5134=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon135=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error136=== PAUSE TestParsePathInfoJSON/Nix_format137=== PAUSE TestPathInfoCACompatibility/null_ca_field138--- PASS: TestScriptTokenScriptFails (0.00s)1392026/09/10 17:36:36 ERROR Upload failed error="bad path" count=3140=== RUN TestPathInfoCACompatibility/old_string_format_-_text141=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter142=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error143=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error144=== RUN TestParsePathInfoJSON/Lix_format145=== RUN TestEncodeNixBase32/test_string_hash146=== PAUSE TestEncodeNixBase32/test_string_hash147=== RUN TestEncodeNixBase32/empty_input148--- PASS: TestEncodeNixBase32WithRealHash (0.00s)149=== PAUSE TestEncodeNixBase32/empty_input150=== CONT TestScriptTokenNoExpiryRerunsEveryCall1512026/09/10 17:36:36 ERROR Upload failed error="connection refused" count=201522026/09/10 17:36:36 ERROR Server seems unavailable, giving up on batch untried=17153=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1542026/09/10 17:36:36 WARN Rate limiter enabled after throttle name=server-test rate=5155=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths156=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text157=== PAUSE TestConvertHashToNix32/already_Nix32_format1582026/09/10 17:36:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35475159=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon160=== PAUSE TestParsePathInfoJSON/Lix_format161=== CONT TestFileTokenEmpty162=== CONT TestStreamPushReportsEveryPath163=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter164=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error165=== CONT TestStreamPushBatchesUnderLoad166=== CONT TestFileTokenMissing167=== RUN TestParsePathInfoJSON/empty_input168--- PASS: TestScriptTokenEmptyToken (0.01s)169=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter170=== CONT TestShellSplitErrors171=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive172=== CONT TestPartSizeForNAR173=== CONT TestUploadMultipart_SupersededByPeer174=== CONT TestFileTokenReadsAndCaches1752026/09/10 17:36:36 WARN Rate limiter backed off name=server-test rate=5176=== CONT TestCaseHackSuffix1772026/09/10 17:36:36 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35475178=== CONT TestFilterOversizedClosures179=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths180=== CONT TestEncodeNixBase32/test_string_hash181=== RUN TestFilterOversizedClosures/no_limit_keeps_everything182=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything183=== RUN TestUploadMultipart_SupersededByPeer/exists184=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped185=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped186=== RUN TestConvertHashToNix32/invalid_format187=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error188=== CONT TestShellSplit189=== CONT TestRateLimiterFeedback/429_enables_limiter190=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter191=== PAUSE TestParsePathInfoJSON/empty_input192=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI193=== RUN TestSetClientTLSErrors/missing_cert_file194--- PASS: TestScriptTokenBadJSON (0.01s)195=== RUN TestPartSizeForNAR/zero_stays_at_minimum196=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive197=== CONT TestEncodeNixBase32/empty_input198=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths199=== CONT TestGetStorePathHash/valid_store_path200=== PAUSE TestUploadMultipart_SupersededByPeer/exists201=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error202=== RUN TestFilterOversizedClosures/all_closures_skipped203=== PAUSE TestConvertHashToNix32/invalid_format204=== CONT TestGetStorePathHash/basename_without_hyphen_should_error205=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter206=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI207--- PASS: TestStreamPushIsolatesFailures (0.01s)208=== RUN TestParsePathInfoJSON/whitespace_only209=== PAUSE TestSetClientTLSErrors/missing_cert_file210=== CONT TestRateLimiterFeedback/503_enables_limiter211=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum212=== RUN TestPathInfoCACompatibility/new_structured_format_-_text213=== CONT TestConvertHashToNix32/SRI_format_to_Nix32214=== CONT TestConvertHashToNix32/invalid_format215=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text216=== RUN TestSetClientTLSErrors/missing_key_file217=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512218=== RUN TestPartSizeForNAR/small_stays_at_minimum219--- PASS: TestFileTokenMissing (0.00s)220=== CONT TestConvertHashToNix32/already_Nix32_format221--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)222=== PAUSE TestParsePathInfoJSON/whitespace_only223=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512224--- PASS: TestStreamPushGivesUpOnDeadServer (0.04s)225=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512226=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon227=== RUN TestParsePathInfoJSON/invalid_JSON228=== PAUSE TestSetClientTLSErrors/missing_key_file229=== RUN TestSetClientTLSErrors/missing_ca_file230--- PASS: TestShellSplitErrors (0.00s)231=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method232=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method233=== CONT TestPathInfoCACompatibility/null_ca_field234=== CONT TestPathInfoCACompatibility/new_structured_format_-_text2352026/09/10 17:36:36 WARN Rate limiter enabled after throttle name=server-test rate=5236=== RUN TestUploadMultipart_SupersededByPeer/missing2372026/09/10 17:36:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:38047238=== PAUSE TestParsePathInfoJSON/invalid_JSON2392026/09/10 17:36:36 WARN Rate limiter enabled after throttle name=server-test rate=5240=== CONT TestParsePathInfoJSON/Nix_format2412026/09/10 17:36:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:44401242=== RUN TestSetClientTLS/rejects_connection_without_client_cert243=== PAUSE TestSetClientTLSErrors/missing_ca_file244--- PASS: TestDoServerRequestAttachesToken (0.05s)245=== PAUSE TestPartSizeForNAR/small_stays_at_minimum246=== CONT TestPathInfoCACompatibility/old_string_format_-_text247=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum2482026/09/10 17:36:36 WARN Rate limiter backed off name=server-test rate=5249=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive250=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method251=== PAUSE TestFilterOversizedClosures/all_closures_skipped252=== CONT TestFilterOversizedClosures/all_closures_skipped253=== CONT TestFilterOversizedClosures/no_limit_keeps_everything2542026/09/10 17:36:36 WARN Rate limiter backed off name=server-test rate=5255=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum2562026/09/10 17:36:36 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=50257=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI258=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2592026/09/10 17:36:36 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=2000260=== PAUSE TestUploadMultipart_SupersededByPeer/missing261=== CONT TestUploadMultipart_SupersededByPeer/exists262=== CONT TestParsePathInfoJSON/whitespace_only263=== CONT TestParsePathInfoJSON/invalid_JSON264=== CONT TestParsePathInfoJSON/empty_input265=== CONT TestParsePathInfoJSON/Lix_format266=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert267=== RUN TestSetClientTLSErrors/invalid_ca_file268--- PASS: TestStreamPushReportsEveryPath (0.04s)269=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)270=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts271=== CONT TestUploadMultipart_SupersededByPeer/missing272=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts273=== RUN TestPartSizeForNAR/1_TiB274=== PAUSE TestPartSizeForNAR/1_TiB275=== RUN TestPartSizeForNAR/5_TiB_S3_max_object276=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object277=== RUN TestPartSizeForNAR/capped_at_5_GiB278=== PAUSE TestPartSizeForNAR/capped_at_5_GiB279=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA280--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.05s)281--- PASS: TestFileTokenEmpty (0.04s)282=== PAUSE TestSetClientTLSErrors/invalid_ca_file283=== CONT TestSetClientTLSErrors/missing_cert_file284=== CONT TestSetClientTLSErrors/invalid_ca_file285=== CONT TestSetClientTLSErrors/missing_ca_file286=== CONT TestSetClientTLSErrors/missing_key_file287=== CONT TestPartSizeForNAR/capped_at_5_GiB288=== CONT TestPartSizeForNAR/5_TiB_S3_max_object289=== CONT TestPartSizeForNAR/1_TiB290=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts291=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum292=== CONT TestPartSizeForNAR/small_stays_at_minimum293=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA294--- PASS: TestFileTokenReadsAndCaches (0.00s)295--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)296=== CONT TestPartSizeForNAR/zero_stays_at_minimum297=== RUN TestSetClientTLS/preserves_debug_logging_transport298--- PASS: TestDumpPathSingleFile (0.05s)299--- PASS: TestShellSplit (0.00s)300--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)301=== PAUSE TestSetClientTLS/preserves_debug_logging_transport302--- PASS: TestEncodeNixBase32 (0.00s)303 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)304 --- PASS: TestEncodeNixBase32/empty_input (0.00s)305=== CONT TestSetClientTLS/preserves_debug_logging_transport306=== CONT TestSetClientTLS/rejects_connection_without_client_cert307=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA308--- PASS: TestPartSizeForNAR (0.01s)309 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)310 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)311 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)312 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)313 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)314 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)315 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)316--- PASS: TestConvertHashToNix32 (0.05s)317 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)318 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)319 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)320--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)321 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)322 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)323--- PASS: TestGetStorePathHash (0.01s)324 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)325 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)326 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)327 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)328--- PASS: TestRateLimiterFeedback (0.01s)329 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)330 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)331 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)332 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)333--- PASS: TestFilterOversizedClosures (0.01s)334 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)335 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)336 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)337--- PASS: TestPathInfoCACompatibility (0.05s)338 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)339 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)340 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)341 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)342 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)343--- PASS: TestPathInfoHashCompatibility (0.05s)344 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)345 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)346 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)347 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)348--- PASS: TestParsePathInfoJSON (0.05s)349 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)350 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)351 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)352 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)353 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)354--- PASS: TestSetClientTLSErrors (0.05s)355 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)356 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)357 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)358 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)359--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)360 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)361 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)3622026/09/10 17:36:36 http: TLS handshake error from 127.0.0.1:45260: remote error: tls: bad certificate363--- PASS: TestSetClientTLS (0.05s)364 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)365 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)366 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)367--- PASS: TestCaseHackSuffix (0.04s)368--- PASS: TestDumpPathWriterError (0.09s)369--- PASS: TestDumpPathMatchesNix (0.14s)370--- PASS: TestStreamPushBatchesUnderLoad (0.14s)371--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)372PASS373Running server tests...374The files belonging to this database system will be owned by user "nixbld".375This user must also own the server process.376377The database cluster will be initialized with locale "C".378The default database encoding has accordingly been set to "SQL_ASCII".379The default text search configuration will be set to "english".380381Data page checksums are enabled.382383creating directory /build/postgres58231078/data ... ok384creating subdirectories ... ok385selecting dynamic shared memory implementation ... posix386selecting default "max_connections" ... 100387selecting default "shared_buffers" ... 128MB388selecting default time zone ... UTC389creating configuration files ... ok390running bootstrap script ... ok391performing post-bootstrap initialization ... ok392syncing data to disk ... ok393394initdb: warning: enabling "trust" authentication for local connections395initdb: 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.396397Success. You can now start the database server using:398399 pg_ctl -D /build/postgres58231078/data -l logfile start400401/build/postgres58231078:5432 - no response4022026-09-10 17:36:38.261 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4032026-09-10 17:36:38.262 UTC [128] LOG: listening on Unix socket "/build/postgres58231078/.s.PGSQL.5432"4042026-09-10 17:36:38.266 UTC [135] LOG: database system was shut down at 2026-09-10 17:36:37 UTC4052026-09-10 17:36:38.270 UTC [128] LOG: database system is ready to accept connections406/build/postgres58231078:5432 - accepting connections407=== RUN TestService_AuthMiddleware408=== PAUSE TestService_AuthMiddleware409=== RUN TestService_AuthMiddleware_MTLSProxyHeader410=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader411=== RUN TestService_AuthMiddleware_MTLSBoundSubjects412=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects413=== RUN TestService_ReadAuthMiddleware414=== PAUSE TestService_ReadAuthMiddleware415=== RUN TestService_AuthMiddleware_OIDC416=== PAUSE TestService_AuthMiddleware_OIDC417=== RUN TestService_RequireScope_OIDC418=== PAUSE TestService_RequireScope_OIDC419=== RUN TestService_ReadScope_PublicByDefault420=== PAUSE TestService_ReadScope_PublicByDefault421=== RUN TestCacheConfigHandler422=== PAUSE TestCacheConfigHandler423=== RUN TestCacheStatsHandler424=== PAUSE TestCacheStatsHandler425=== RUN TestClaim_BuildWaitComplete426=== PAUSE TestClaim_BuildWaitComplete427=== RUN TestClaim_GCMarkedOutputCountsAsAbsent428=== PAUSE TestClaim_GCMarkedOutputCountsAsAbsent429=== RUN TestClaim_TooManyStreams430=== PAUSE TestClaim_TooManyStreams431=== RUN TestClaim_HolderDisconnectKeepsClaim432=== PAUSE TestClaim_HolderDisconnectKeepsClaim433=== RUN TestClaim_FailWakesWaitersButIsNotRemembered434=== PAUSE TestClaim_FailWakesWaitersButIsNotRemembered435=== RUN TestClaim_FailWithoutKindReleases436=== PAUSE TestClaim_FailWithoutKindReleases437=== RUN TestClaim_StaleHeartbeatStolen438=== PAUSE TestClaim_StaleHeartbeatStolen439=== RUN TestClaim_TwoInstances440=== PAUSE TestClaim_TwoInstances441=== RUN TestClaim_InputsTouched442=== PAUSE TestClaim_InputsTouched443=== RUN TestClaim_StreamsThroughServer444=== PAUSE TestClaim_StreamsThroughServer445=== RUN TestClientCADerivations446=== PAUSE TestClientCADerivations447=== RUN TestClientErrorHandling448=== PAUSE TestClientErrorHandling449=== RUN TestClientIntegration450=== PAUSE TestClientIntegration451=== RUN TestClientMultipleUploads452=== PAUSE TestClientMultipleUploads453=== RUN TestClientWithDependencies454=== PAUSE TestClientWithDependencies455=== RUN TestPinProtectsFromGC456=== PAUSE TestPinProtectsFromGC457=== RUN TestResolveDBConnectionString458=== PAUSE TestResolveDBConnectionString459=== RUN TestGCAdvisoryLockBlocksConcurrentRun4602026-09-10 17:36:40.599 UTC [537] ERROR: relation "goose_db_version" does not exist at character 364612026-09-10 17:36:40.599 UTC [537] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4622026/09/10 17:36:40 OK 20241026095416_initial_model.sql (11.49ms)4632026/09/10 17:36:40 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)4642026/09/10 17:36:40 OK 20251218171726_add_pins.sql (3.84ms)4652026/09/10 17:36:40 OK 20260628120000_add_object_size_and_stats.sql (2.94ms)4662026/09/10 17:36:40 OK 20260905000000_add_claims.sql (3.5ms)4672026/09/10 17:36:40 goose: successfully migrated database to version: 202609050000004682026/09/10 17:36:40 OK 1_commit_pending_closure.sql (1.85ms)4692026/09/10 17:36:40 OK 2_object_stats_trigger.sql (992.37µs)4702026/09/10 17:36:40 goose: up to current file version: 2471--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.22s)472=== RUN TestGCBugBareHashReferences473=== PAUSE TestGCBugBareHashReferences474=== RUN TestGCMetrics475=== PAUSE TestGCMetrics476=== RUN TestGCTaskStore_StartNew477=== PAUSE TestGCTaskStore_StartNew478=== RUN TestGCTaskStore_DeduplicateSameParams479=== PAUSE TestGCTaskStore_DeduplicateSameParams480=== RUN TestGCTaskStore_ConflictDifferentParams481=== PAUSE TestGCTaskStore_ConflictDifferentParams482=== RUN TestGCTaskStore_GetEmpty483=== PAUSE TestGCTaskStore_GetEmpty484=== RUN TestGCTaskStore_GetReturnsLatest485=== PAUSE TestGCTaskStore_GetReturnsLatest486=== RUN TestGCTaskStore_CompletedAllowsNewTask487=== PAUSE TestGCTaskStore_CompletedAllowsNewTask488=== RUN TestGCTaskStore_PhaseUpdates489=== PAUSE TestGCTaskStore_PhaseUpdates490=== RUN TestGCTaskStore_Fail491=== PAUSE TestGCTaskStore_Fail492=== RUN TestGracefulShutdownDrainsInflight493=== PAUSE TestGracefulShutdownDrainsInflight494=== RUN TestService_healthCheckHandler495=== PAUSE TestService_healthCheckHandler496=== RUN TestService_readinessHandler497=== PAUSE TestService_readinessHandler498=== RUN TestGenerateLandingPage499=== PAUSE TestGenerateLandingPage500=== RUN TestCacheConfigHandlerMaxNarSize501=== PAUSE TestCacheConfigHandlerMaxNarSize502=== RUN TestCreatePendingClosureRejectsOversizedNAR503=== PAUSE TestCreatePendingClosureRejectsOversizedNAR504=== RUN TestNARDeduplicationMetadataUploadBug505=== PAUSE TestNARDeduplicationMetadataUploadBug506=== RUN TestMetricsInventory507=== PAUSE TestMetricsInventory508=== RUN TestService_NativeMTLS509=== PAUSE TestService_NativeMTLS510=== RUN TestServerTLSConfig511=== PAUSE TestServerTLSConfig512=== RUN TestMultipartCleanup513=== PAUSE TestMultipartCleanup514=== RUN TestObjectStatsTrigger515=== PAUSE TestObjectStatsTrigger516=== RUN TestOrphanedObjectsGC517=== PAUSE TestOrphanedObjectsGC518=== RUN TestOrphanedObjectsGCStressTest519=== PAUSE TestOrphanedObjectsGCStressTest520=== RUN TestResurrectedObjectNotDeleted521=== PAUSE TestResurrectedObjectNotDeleted522=== RUN TestParseSingleRange523=== PAUSE TestParseSingleRange524=== RUN TestIsValidCachePath525=== PAUSE TestIsValidCachePath526=== RUN TestReadProxyNarinfo527=== PAUSE TestReadProxyNarinfo528=== RUN TestReadProxyNarinfoAlreadyDecompressed529=== PAUSE TestReadProxyNarinfoAlreadyDecompressed530=== RUN TestReadProxyNarStreaming531=== PAUSE TestReadProxyNarStreaming532=== RUN TestReadProxy404533=== PAUSE TestReadProxy404534=== RUN TestReadProxyInvalidPath535=== PAUSE TestReadProxyInvalidPath536=== RUN TestReadProxyHead537=== PAUSE TestReadProxyHead538=== RUN TestReadProxyConditionalGet539=== PAUSE TestReadProxyConditionalGet540=== RUN TestReadProxyRootRedirectsToIndexHTML541=== PAUSE TestReadProxyRootRedirectsToIndexHTML542=== RUN TestReadProxyDisabled543=== PAUSE TestReadProxyDisabled544=== RUN TestReadRedirectNar545=== PAUSE TestReadRedirectNar546=== RUN TestReadRedirectKeepsNarinfoProxied547=== PAUSE TestReadRedirectKeepsNarinfoProxied548=== RUN TestReadProxyRangeRequest549=== PAUSE TestReadProxyRangeRequest550=== RUN TestReadRedirectUsesPublicS3URL551=== PAUSE TestReadRedirectUsesPublicS3URL552=== RUN TestRedundantMultipartUpload553=== PAUSE TestRedundantMultipartUpload554=== RUN TestCompleteMultipartUpload_ErrorButObjectExists555=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists556=== RUN TestCompletedNarNotReofferedAcrossClosures557=== PAUSE TestCompletedNarNotReofferedAcrossClosures558=== RUN TestPresignedUploadRegisteredBeforeCommit559=== PAUSE TestPresignedUploadRegisteredBeforeCommit560=== RUN TestService_Rustfstest561=== PAUSE TestService_Rustfstest562=== RUN TestParseSize563=== PAUSE TestParseSize564=== RUN TestSkippedUploadsHandler565=== PAUSE TestSkippedUploadsHandler566=== RUN TestSystemdListenerNotActivated567--- PASS: TestSystemdListenerNotActivated (0.00s)568=== RUN TestWatchdogBeatsWhenHealthy569--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)570=== RUN TestWatchdogSkipsWhenUnhealthy5712026/09/10 17:36:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5722026/09/10 17:36:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5732026/09/10 17:36:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5742026/09/10 17:36:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5752026/09/10 17:36:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5762026/09/10 17:36:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5772026/09/10 17:36:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5782026/09/10 17:36:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5792026/09/10 17:36:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5802026/09/10 17:36:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"581--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)582=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle583=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle584=== RUN TestProxyWriteTimeout585=== PAUSE TestProxyWriteTimeout586=== RUN TestIsValidUploadKey587=== PAUSE TestIsValidUploadKey588=== RUN TestUploadHandlersRejectInvalidKeys589=== PAUSE TestUploadHandlersRejectInvalidKeys590=== RUN TestUploadHandlersRejectOversizedBody591=== PAUSE TestUploadHandlersRejectOversizedBody592=== RUN TestService_cleanupPendingClosuresHandler593=== PAUSE TestService_cleanupPendingClosuresHandler594=== RUN TestService_createPendingClosureHandler595=== PAUSE TestService_createPendingClosureHandler596=== RUN TestService_verifyS3Integrity597=== PAUSE TestService_verifyS3Integrity598=== RUN TestCompleteMultipartUnregistered599=== PAUSE TestCompleteMultipartUnregistered600=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT601=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT602=== CONT TestPresignedUploadRegisteredBeforeCommit603=== CONT TestReadProxyRootRedirectsToIndexHTML604=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle605=== CONT TestService_AuthMiddleware606=== CONT TestGCTaskStore_ConflictDifferentParams607--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)608=== CONT TestUploadHandlersRejectInvalidKeys609=== CONT TestCompletedNarNotReofferedAcrossClosures610=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info611=== CONT TestCompleteMultipartUpload_ErrorButObjectExists612=== CONT TestRedundantMultipartUpload613=== CONT TestReadRedirectUsesPublicS3URL614=== CONT TestReadProxyRangeRequest615=== CONT TestReadRedirectKeepsNarinfoProxied616=== CONT TestReadRedirectNar617=== CONT TestReadProxyDisabled618=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT619=== CONT TestCompleteMultipartUnregistered620=== CONT TestService_verifyS3Integrity621=== CONT TestService_createPendingClosureHandler622=== CONT TestService_cleanupPendingClosuresHandler623=== CONT TestUploadHandlersRejectOversizedBody624=== CONT TestReadProxyConditionalGet625=== CONT TestReadProxyHead626=== CONT TestReadProxyInvalidPath627=== CONT TestReadProxy404628=== CONT TestReadProxyNarStreaming629=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info630=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal631=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal632=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key633=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key634=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key635=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key636=== CONT TestReadProxyNarinfoAlreadyDecompressed6372026-09-10 17:36:41.080 UTC [608] ERROR: relation "goose_db_version" does not exist at character 366382026-09-10 17:36:41.080 UTC [608] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6392026-09-10 17:36:41.084 UTC [609] ERROR: relation "goose_db_version" does not exist at character 366402026-09-10 17:36:41.084 UTC [609] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6412026-09-10 17:36:41.091 UTC [610] ERROR: relation "goose_db_version" does not exist at character 366422026-09-10 17:36:41.091 UTC [610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6432026-09-10 17:36:41.091 UTC [611] ERROR: relation "goose_db_version" does not exist at character 366442026-09-10 17:36:41.091 UTC [611] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC645=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure646=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure647=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart648=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart649=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts650=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts651=== CONT TestReadProxyNarinfo6522026-09-10 17:36:41.149 UTC [614] ERROR: relation "goose_db_version" does not exist at character 366532026-09-10 17:36:41.149 UTC [614] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6542026/09/10 17:36:41 OK 20241026095416_initial_model.sql (35.95ms)6552026-09-10 17:36:41.161 UTC [615] ERROR: relation "goose_db_version" does not exist at character 366562026-09-10 17:36:41.161 UTC [615] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6572026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (4.23ms)6582026-09-10 17:36:41.166 UTC [616] ERROR: relation "goose_db_version" does not exist at character 366592026-09-10 17:36:41.166 UTC [616] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6602026/09/10 17:36:41 OK 20241026095416_initial_model.sql (46.89ms)6612026-09-10 17:36:41.181 UTC [617] ERROR: relation "goose_db_version" does not exist at character 366622026-09-10 17:36:41.181 UTC [617] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6632026/09/10 17:36:41 OK 20251218171726_add_pins.sql (19.2ms)6642026/09/10 17:36:41 OK 20241026095416_initial_model.sql (27.43ms)6652026/09/10 17:36:41 OK 20241026095416_initial_model.sql (58.43ms)6662026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (15.43ms)6672026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (3.27ms)6682026/09/10 17:36:41 OK 20241026095416_initial_model.sql (51.89ms)6692026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (5.59ms)6702026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (9.38ms)6712026/09/10 17:36:41 OK 20251218171726_add_pins.sql (4.98ms)6722026/09/10 17:36:41 OK 20251218171726_add_pins.sql (9.85ms)6732026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (5.41ms)6742026/09/10 17:36:41 OK 20260905000000_add_claims.sql (6.18ms)6752026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000006762026/09/10 17:36:41 OK 20251218171726_add_pins.sql (9.02ms)6772026/09/10 17:36:41 OK 20241026095416_initial_model.sql (29.39ms)6782026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (7.78ms)6792026/09/10 17:36:41 OK 1_commit_pending_closure.sql (12.77ms)6802026/09/10 17:36:41 OK 20251218171726_add_pins.sql (17.81ms)6812026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (18.43ms)6822026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (13.93ms)6832026/09/10 17:36:41 OK 20241026095416_initial_model.sql (27.86ms)6842026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (14.26ms)6852026/09/10 17:36:41 OK 20260905000000_add_claims.sql (14.6ms)6862026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000006872026/09/10 17:36:41 OK 2_object_stats_trigger.sql (6.24ms)6882026/09/10 17:36:41 goose: up to current file version: 26892026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (3.74ms)6902026/09/10 17:36:41 OK 20241026095416_initial_model.sql (24.84ms)6912026/09/10 17:36:41 OK 20260905000000_add_claims.sql (6.84ms)6922026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000006932026/09/10 17:36:41 OK 20251218171726_add_pins.sql (6.48ms)6942026/09/10 17:36:41 OK 1_commit_pending_closure.sql (4.54ms)6952026/09/10 17:36:41 OK 20260905000000_add_claims.sql (8.65ms)6962026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000006972026/09/10 17:36:41 OK 2_object_stats_trigger.sql (3.81ms)6982026/09/10 17:36:41 goose: up to current file version: 26992026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (11.29ms)7002026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (6.12ms)7012026/09/10 17:36:41 OK 20251218171726_add_pins.sql (8.98ms)7022026/09/10 17:36:41 OK 1_commit_pending_closure.sql (6.14ms)7032026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (7.56ms)7042026/09/10 17:36:41 OK 1_commit_pending_closure.sql (6.31ms)7052026/09/10 17:36:41 OK 20260905000000_add_claims.sql (5.73ms)7062026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000007072026-09-10 17:36:41.233 UTC [618] ERROR: relation "goose_db_version" does not exist at character 367082026-09-10 17:36:41.233 UTC [618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7092026/09/10 17:36:41 OK 20251218171726_add_pins.sql (7.4ms)7102026/09/10 17:36:41 OK 2_object_stats_trigger.sql (5.63ms)7112026/09/10 17:36:41 goose: up to current file version: 27122026/09/10 17:36:41 OK 2_object_stats_trigger.sql (3.96ms)7132026/09/10 17:36:41 goose: up to current file version: 27142026-09-10 17:36:41.236 UTC [619] ERROR: relation "goose_db_version" does not exist at character 367152026-09-10 17:36:41.236 UTC [619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7162026/09/10 17:36:41 OK 1_commit_pending_closure.sql (4.79ms)7172026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (8.39ms)7182026/09/10 17:36:41 OK 20260905000000_add_claims.sql (5.43ms)7192026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000007202026-09-10 17:36:41.248 UTC [623] ERROR: relation "goose_db_version" does not exist at character 367212026-09-10 17:36:41.248 UTC [623] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7222026-09-10 17:36:41.248 UTC [624] ERROR: relation "goose_db_version" does not exist at character 367232026-09-10 17:36:41.248 UTC [624] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026-09-10 17:36:41.249 UTC [625] ERROR: relation "goose_db_version" does not exist at character 367252026-09-10 17:36:41.249 UTC [625] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7262026-09-10 17:36:41.250 UTC [626] ERROR: relation "goose_db_version" does not exist at character 367272026-09-10 17:36:41.250 UTC [626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7282026/09/10 17:36:41 OK 2_object_stats_trigger.sql (16.61ms)7292026/09/10 17:36:41 goose: up to current file version: 27302026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (22.38ms)7312026/09/10 17:36:41 OK 1_commit_pending_closure.sql (18.7ms)7322026/09/10 17:36:41 OK 20260905000000_add_claims.sql (19.29ms)7332026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000007342026/09/10 17:36:41 OK 2_object_stats_trigger.sql (3.23ms)7352026/09/10 17:36:41 goose: up to current file version: 27362026/09/10 17:36:41 OK 1_commit_pending_closure.sql (6.79ms)7372026/09/10 17:36:41 OK 20260905000000_add_claims.sql (9.06ms)7382026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000007392026/09/10 17:36:41 OK 2_object_stats_trigger.sql (3.47ms)7402026/09/10 17:36:41 goose: up to current file version: 27412026/09/10 17:36:41 OK 1_commit_pending_closure.sql (4.18ms)7422026-09-10 17:36:41.272 UTC [628] ERROR: relation "goose_db_version" does not exist at character 367432026-09-10 17:36:41.272 UTC [628] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7442026-09-10 17:36:41.272 UTC [627] ERROR: relation "goose_db_version" does not exist at character 367452026-09-10 17:36:41.272 UTC [627] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7462026/09/10 17:36:41 OK 20241026095416_initial_model.sql (12.99ms)7472026/09/10 17:36:41 OK 20241026095416_initial_model.sql (13.99ms)7482026/09/10 17:36:41 OK 20241026095416_initial_model.sql (14.25ms)7492026-09-10 17:36:41.274 UTC [629] ERROR: relation "goose_db_version" does not exist at character 367502026-09-10 17:36:41.274 UTC [629] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7512026/09/10 17:36:41 OK 2_object_stats_trigger.sql (4ms)7522026/09/10 17:36:41 goose: up to current file version: 27532026-09-10 17:36:41.275 UTC [630] ERROR: relation "goose_db_version" does not exist at character 367542026-09-10 17:36:41.275 UTC [630] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7552026-09-10 17:36:41.275 UTC [631] ERROR: relation "goose_db_version" does not exist at character 367562026-09-10 17:36:41.275 UTC [631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7572026-09-10 17:36:41.275 UTC [633] ERROR: relation "goose_db_version" does not exist at character 367582026-09-10 17:36:41.275 UTC [633] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7592026-09-10 17:36:41.276 UTC [634] ERROR: relation "goose_db_version" does not exist at character 367602026-09-10 17:36:41.276 UTC [634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7612026-09-10 17:36:41.276 UTC [632] ERROR: relation "goose_db_version" does not exist at character 367622026-09-10 17:36:41.276 UTC [632] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7632026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (4.76ms)7642026/09/10 17:36:41 OK 20241026095416_initial_model.sql (18.83ms)7652026-09-10 17:36:41.279 UTC [636] ERROR: relation "goose_db_version" does not exist at character 367662026-09-10 17:36:41.279 UTC [636] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7672026/09/10 17:36:41 OK 20241026095416_initial_model.sql (19.43ms)7682026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (5.56ms)7692026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (5.47ms)7702026/09/10 17:36:41 OK 20241026095416_initial_model.sql (19.91ms)7712026-09-10 17:36:41.280 UTC [635] ERROR: relation "goose_db_version" does not exist at character 367722026-09-10 17:36:41.280 UTC [635] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7732026/09/10 17:36:41 OK 20251218171726_add_pins.sql (5.63ms)7742026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (4.02ms)7752026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (4.29ms)7762026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (4.17ms)7772026/09/10 17:36:41 OK 20251218171726_add_pins.sql (5.41ms)7782026/09/10 17:36:41 OK 20251218171726_add_pins.sql (5.54ms)7792026/09/10 17:36:41 OK 20251218171726_add_pins.sql (4.63ms)7802026/09/10 17:36:41 OK 20251218171726_add_pins.sql (5.13ms)7812026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (6.34ms)7822026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (5.93ms)7832026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (5.91ms)7842026/09/10 17:36:41 OK 20251218171726_add_pins.sql (6.46ms)7852026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)7862026/09/10 17:36:41 OK 20260905000000_add_claims.sql (4.77ms)7872026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000007882026/09/10 17:36:41 OK 20260905000000_add_claims.sql (5.03ms)7892026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000007902026/09/10 17:36:41 OK 20241026095416_initial_model.sql (14.01ms)7912026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (6.42ms)7922026/09/10 17:36:41 OK 20241026095416_initial_model.sql (14.81ms)7932026/09/10 17:36:41 OK 20260905000000_add_claims.sql (6.58ms)7942026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000007952026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (6.51ms)7962026/09/10 17:36:41 OK 20241026095416_initial_model.sql (16.31ms)7972026/09/10 17:36:41 OK 1_commit_pending_closure.sql (4.22ms)7982026/09/10 17:36:41 OK 20260905000000_add_claims.sql (5.92ms)7992026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000008002026/09/10 17:36:41 OK 20241026095416_initial_model.sql (15.44ms)8012026/09/10 17:36:41 OK 20241026095416_initial_model.sql (15.24ms)8022026/09/10 17:36:41 OK 20241026095416_initial_model.sql (15.3ms)8032026/09/10 17:36:41 OK 20241026095416_initial_model.sql (14.34ms)8042026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)8052026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (3.11ms)8062026/09/10 17:36:41 OK 1_commit_pending_closure.sql (3.46ms)8072026/09/10 17:36:41 OK 20241026095416_initial_model.sql (12.68ms)8082026/09/10 17:36:41 OK 20241026095416_initial_model.sql (15.41ms)8092026/09/10 17:36:41 OK 1_commit_pending_closure.sql (3.68ms)8102026/09/10 17:36:41 OK 20241026095416_initial_model.sql (14.33ms)8112026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (3.75ms)8122026/09/10 17:36:41 OK 2_object_stats_trigger.sql (3.46ms)8132026/09/10 17:36:41 OK 20260905000000_add_claims.sql (6.24ms)8142026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000008152026/09/10 17:36:41 OK 2_object_stats_trigger.sql (2.68ms)8162026/09/10 17:36:41 goose: up to current file version: 28172026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)8182026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (3.18ms)8192026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (3.3ms)8202026/09/10 17:36:41 goose: up to current file version: 28212026/09/10 17:36:41 OK 1_commit_pending_closure.sql (3.32ms)8222026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (3.49ms)8232026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)8242026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)8252026/09/10 17:36:41 OK 20260905000000_add_claims.sql (5.66ms)8262026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000008272026/09/10 17:36:41 OK 20251218171726_add_pins.sql (5.57ms)8282026/09/10 17:36:41 OK 20251218171726_add_pins.sql (5.79ms)8292026/09/10 17:36:41 OK 2_object_stats_trigger.sql (3.95ms)8302026/09/10 17:36:41 goose: up to current file version: 28312026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (3.93ms)8322026/09/10 17:36:41 OK 1_commit_pending_closure.sql (4.12ms)8332026/09/10 17:36:41 OK 2_object_stats_trigger.sql (3.61ms)8342026/09/10 17:36:41 goose: up to current file version: 28352026/09/10 17:36:41 OK 20251218171726_add_pins.sql (6.48ms)8362026/09/10 17:36:41 OK 20251218171726_add_pins.sql (5.04ms)8372026/09/10 17:36:41 OK 20251218171726_add_pins.sql (4.83ms)8382026/09/10 17:36:41 OK 20251218171726_add_pins.sql (4.95ms)8392026/09/10 17:36:41 OK 20251218171726_add_pins.sql (5.47ms)8402026/09/10 17:36:41 OK 20251218171726_add_pins.sql (5.39ms)8412026/09/10 17:36:41 OK 1_commit_pending_closure.sql (4.64ms)8422026/09/10 17:36:41 OK 20251218171726_add_pins.sql (5.3ms)843--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.35s)844=== CONT TestCreatePendingClosureRejectsOversizedNAR8452026/09/10 17:36:41 OK 2_object_stats_trigger.sql (2.02ms)8462026/09/10 17:36:41 goose: up to current file version: 28472026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)8482026/09/10 17:36:41 OK 20251218171726_add_pins.sql (3.56ms)8492026/09/10 17:36:41 INFO Received uploads request method=POST path=/api/pending_closures8502026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)851--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)852=== CONT TestCacheConfigHandlerMaxNarSize853--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)854=== CONT TestGenerateLandingPage8552026/09/10 17:36:41 OK 2_object_stats_trigger.sql (2.76ms)8562026/09/10 17:36:41 goose: up to current file version: 28572026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)8582026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)8592026/09/10 17:36:41 OK 20260905000000_add_claims.sql (4.46ms)8602026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000008612026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (5.13ms)8622026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (4.99ms)8632026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (5.03ms)8642026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (5.23ms)8652026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (5.13ms)8662026/09/10 17:36:41 OK 20260905000000_add_claims.sql (4.04ms)8672026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000008682026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (4.93ms)8692026/09/10 17:36:41 OK 20260905000000_add_claims.sql (2.9ms)8702026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000008712026/09/10 17:36:41 OK 20260905000000_add_claims.sql (3.72ms)8722026/09/10 17:36:41 goose: successfully migrated database to version: 20260905000000873--- PASS: TestGenerateLandingPage (0.01s)874=== CONT TestService_readinessHandler8752026/09/10 17:36:41 OK 1_commit_pending_closure.sql (3.69ms)8762026/09/10 17:36:41 OK 1_commit_pending_closure.sql (3.94ms)8772026/09/10 17:36:41 OK 20260905000000_add_claims.sql (4.05ms)8782026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000008792026/09/10 17:36:41 OK 20260905000000_add_claims.sql (3.89ms)8802026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000008812026/09/10 17:36:41 OK 1_commit_pending_closure.sql (2.21ms)8822026/09/10 17:36:41 OK 20260905000000_add_claims.sql (4.06ms)8832026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000008842026/09/10 17:36:41 OK 20260905000000_add_claims.sql (4.5ms)8852026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000008862026/09/10 17:36:41 OK 20260905000000_add_claims.sql (4.32ms)8872026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000008882026/09/10 17:36:41 OK 2_object_stats_trigger.sql (1.02ms)8892026/09/10 17:36:41 goose: up to current file version: 28902026/09/10 17:36:41 OK 1_commit_pending_closure.sql (1.9ms)8912026/09/10 17:36:41 OK 20260905000000_add_claims.sql (5.46ms)8922026/09/10 17:36:41 goose: successfully migrated database to version: 202609050000008932026/09/10 17:36:41 OK 1_commit_pending_closure.sql (1.4ms)8942026/09/10 17:36:41 OK 1_commit_pending_closure.sql (1.57ms)8952026/09/10 17:36:41 OK 2_object_stats_trigger.sql (1.23ms)8962026/09/10 17:36:41 goose: up to current file version: 28972026/09/10 17:36:41 OK 2_object_stats_trigger.sql (1.63ms)8982026/09/10 17:36:41 goose: up to current file version: 28992026/09/10 17:36:41 OK 1_commit_pending_closure.sql (1.96ms)9002026/09/10 17:36:41 OK 2_object_stats_trigger.sql (1.18ms)9012026/09/10 17:36:41 goose: up to current file version: 29022026/09/10 17:36:41 OK 2_object_stats_trigger.sql (892.15µs)9032026/09/10 17:36:41 goose: up to current file version: 29042026/09/10 17:36:41 OK 2_object_stats_trigger.sql (1.13ms)9052026/09/10 17:36:41 goose: up to current file version: 29062026/09/10 17:36:41 OK 1_commit_pending_closure.sql (2.3ms)9072026/09/10 17:36:41 OK 1_commit_pending_closure.sql (2.64ms)9082026/09/10 17:36:41 OK 2_object_stats_trigger.sql (890.15µs)9092026/09/10 17:36:41 goose: up to current file version: 29102026/09/10 17:36:41 OK 1_commit_pending_closure.sql (1.74ms)9112026/09/10 17:36:41 OK 2_object_stats_trigger.sql (955.95µs)9122026/09/10 17:36:41 goose: up to current file version: 29132026/09/10 17:36:41 OK 2_object_stats_trigger.sql (766.93µs)9142026/09/10 17:36:41 goose: up to current file version: 29152026/09/10 17:36:41 OK 2_object_stats_trigger.sql (1.04ms)9162026/09/10 17:36:41 goose: up to current file version: 2917--- PASS: TestReadRedirectNar (0.39s)918=== CONT TestService_healthCheckHandler9192026/09/10 17:36:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9202026/09/10 17:36:41 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst921--- PASS: TestCompleteMultipartUnregistered (0.40s)922=== CONT TestGracefulShutdownDrainsInflight9232026/09/10 17:36:41 INFO Starting HTTP server address=127.0.0.1:407659242026/09/10 17:36:41 INFO Shutdown signal received, draining in-flight requests timeout=10s9252026/09/10 17:36:41 INFO Received uploads request method=POST path=/api/pending_closures9262026-09-10 17:36:41.404 UTC [642] ERROR: relation "goose_db_version" does not exist at character 369272026-09-10 17:36:41.404 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9282026/09/10 17:36:41 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9292026/09/10 17:36:41 INFO Received uploads request method=POST path=/api/pending_closures9302026/09/10 17:36:41 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"931--- PASS: TestService_AuthMiddleware (0.46s)932=== CONT TestGCTaskStore_Fail933--- PASS: TestGCTaskStore_Fail (0.00s)934=== CONT TestGCTaskStore_PhaseUpdates935--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)936=== CONT TestGCTaskStore_CompletedAllowsNewTask937--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)938=== CONT TestNARDeduplicationMetadataUploadBug9392026/09/10 17:36:41 OK 20241026095416_initial_model.sql (11.28ms)940--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.46s)941=== CONT TestIsValidCachePath942=== RUN TestIsValidCachePath/narinfo943=== PAUSE TestIsValidCachePath/narinfo944=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars945=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars946=== RUN TestIsValidCachePath/nar_zst947=== PAUSE TestIsValidCachePath/nar_zst948=== RUN TestIsValidCachePath/nar_xz949=== PAUSE TestIsValidCachePath/nar_xz950=== RUN TestIsValidCachePath/nar_bz2951=== PAUSE TestIsValidCachePath/nar_bz2952=== RUN TestIsValidCachePath/nar_uncompressed953=== PAUSE TestIsValidCachePath/nar_uncompressed954=== RUN TestIsValidCachePath/ls955=== PAUSE TestIsValidCachePath/ls956=== RUN TestIsValidCachePath/log957=== PAUSE TestIsValidCachePath/log958=== RUN TestIsValidCachePath/realisation959=== PAUSE TestIsValidCachePath/realisation960=== RUN TestIsValidCachePath/nix-cache-info961=== PAUSE TestIsValidCachePath/nix-cache-info962=== RUN TestIsValidCachePath/index.html963=== PAUSE TestIsValidCachePath/index.html964=== RUN TestIsValidCachePath/traversal_parent965=== PAUSE TestIsValidCachePath/traversal_parent966=== RUN TestIsValidCachePath/traversal_in_middle9672026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)968=== PAUSE TestIsValidCachePath/traversal_in_middle969=== RUN TestIsValidCachePath/invalid_char_e970=== PAUSE TestIsValidCachePath/invalid_char_e971=== RUN TestIsValidCachePath/invalid_char_u972=== PAUSE TestIsValidCachePath/invalid_char_u973=== RUN TestIsValidCachePath/random_path974=== PAUSE TestIsValidCachePath/random_path975=== RUN TestIsValidCachePath/empty976=== PAUSE TestIsValidCachePath/empty977=== RUN TestIsValidCachePath/leading_slash978=== PAUSE TestIsValidCachePath/leading_slash979=== RUN TestIsValidCachePath/wrong_extension980=== PAUSE TestIsValidCachePath/wrong_extension981=== RUN TestIsValidCachePath/short_hash982=== PAUSE TestIsValidCachePath/short_hash983=== CONT TestGCTaskStore_GetReturnsLatest984--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)985=== CONT TestParseSingleRange986=== RUN TestParseSingleRange/none987=== PAUSE TestParseSingleRange/none988=== RUN TestParseSingleRange/unknown_unit989=== PAUSE TestParseSingleRange/unknown_unit990=== RUN TestParseSingleRange/multi-range_ignored991=== PAUSE TestParseSingleRange/multi-range_ignored992=== RUN TestParseSingleRange/malformed_no_dash993=== PAUSE TestParseSingleRange/malformed_no_dash994=== RUN TestParseSingleRange/malformed_both_empty995=== PAUSE TestParseSingleRange/malformed_both_empty996=== RUN TestParseSingleRange/malformed_end_before_start997=== PAUSE TestParseSingleRange/malformed_end_before_start998=== RUN TestParseSingleRange/closed999=== PAUSE TestParseSingleRange/closed1000=== RUN TestParseSingleRange/open-ended1001=== PAUSE TestParseSingleRange/open-ended1002=== RUN TestParseSingleRange/end_clamped_to_size1003=== PAUSE TestParseSingleRange/end_clamped_to_size1004=== RUN TestParseSingleRange/suffix1005=== PAUSE TestParseSingleRange/suffix1006=== RUN TestParseSingleRange/suffix_exceeds_size1007=== PAUSE TestParseSingleRange/suffix_exceeds_size1008=== RUN TestParseSingleRange/single_byte1009=== PAUSE TestParseSingleRange/single_byte1010=== RUN TestParseSingleRange/start_past_EOF1011=== PAUSE TestParseSingleRange/start_past_EOF1012=== RUN TestParseSingleRange/start_far_past_EOF1013=== PAUSE TestParseSingleRange/start_far_past_EOF1014=== CONT TestGCTaskStore_GetEmpty1015--- PASS: TestGCTaskStore_GetEmpty (0.00s)1016=== CONT TestResurrectedObjectNotDeleted10172026/09/10 17:36:41 OK 20251218171726_add_pins.sql (3.08ms)10182026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (3.06ms)10192026-09-10 17:36:41.434 UTC [646] ERROR: relation "goose_db_version" does not exist at character 3610202026-09-10 17:36:41.434 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10212026/09/10 17:36:41 OK 20260905000000_add_claims.sql (3.67ms)10222026/09/10 17:36:41 goose: successfully migrated database to version: 2026090500000010232026/09/10 17:36:41 OK 1_commit_pending_closure.sql (2.93ms)1024--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1025=== CONT TestOrphanedObjectsGCStressTest10262026/09/10 17:36:41 INFO Received uploads request method=POST path=/api/pending_closures10272026/09/10 17:36:41 OK 2_object_stats_trigger.sql (11.33ms)10282026/09/10 17:36:41 goose: up to current file version: 210292026/09/10 17:36:41 OK 20241026095416_initial_model.sql (11.91ms)10302026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)10312026/09/10 17:36:41 OK 20251218171726_add_pins.sql (3.96ms)10322026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (5.54ms)10332026/09/10 17:36:41 OK 20260905000000_add_claims.sql (4.78ms)10342026/09/10 17:36:41 goose: successfully migrated database to version: 2026090500000010352026/09/10 17:36:41 OK 1_commit_pending_closure.sql (3.33ms)10362026/09/10 17:36:41 OK 2_object_stats_trigger.sql (2.04ms)10372026/09/10 17:36:41 goose: up to current file version: 210382026/09/10 17:36:41 INFO Received uploads request method=POST path=/api/pending_closures1039--- PASS: TestReadProxyRangeRequest (0.54s)1040=== CONT TestParseSize1041--- PASS: TestParseSize (0.00s)1042=== CONT TestOrphanedObjectsGC10432026-09-10 17:36:41.511 UTC [650] ERROR: relation "goose_db_version" does not exist at character 3610442026-09-10 17:36:41.511 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10452026-09-10 17:36:41.515 UTC [651] ERROR: relation "goose_db_version" does not exist at character 3610462026-09-10 17:36:41.515 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1047--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.55s)1048=== CONT TestSkippedUploadsHandler10492026/09/10 17:36:41 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001050--- PASS: TestSkippedUploadsHandler (0.01s)1051=== CONT TestObjectStatsTrigger10522026-09-10 17:36:41.526 UTC [654] ERROR: relation "goose_db_version" does not exist at character 3610532026-09-10 17:36:41.526 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10542026/09/10 17:36:41 OK 20241026095416_initial_model.sql (13.11ms)10552026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)10562026/09/10 17:36:41 OK 20241026095416_initial_model.sql (12.56ms)10572026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)10582026/09/10 17:36:41 OK 20251218171726_add_pins.sql (4.79ms)1059--- PASS: TestReadProxyNarinfo (0.43s)1060=== CONT TestServerTLSConfig1061=== RUN TestServerTLSConfig/no_client_CA1062=== PAUSE TestServerTLSConfig/no_client_CA1063=== RUN TestServerTLSConfig/missing_CA_file1064=== PAUSE TestServerTLSConfig/missing_CA_file1065=== RUN TestServerTLSConfig/not_a_PEM_file1066=== PAUSE TestServerTLSConfig/not_a_PEM_file1067=== CONT TestService_NativeMTLS10682026/09/10 17:36:41 OK 20251218171726_add_pins.sql (7.96ms)10692026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (8.54ms)10702026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (5.97ms)10712026/09/10 17:36:41 OK 20260905000000_add_claims.sql (5.62ms)10722026/09/10 17:36:41 goose: successfully migrated database to version: 2026090500000010732026/09/10 17:36:41 OK 20241026095416_initial_model.sql (17.25ms)10742026/09/10 17:36:41 OK 1_commit_pending_closure.sql (13.41ms)10752026/09/10 17:36:41 OK 20260905000000_add_claims.sql (14.8ms)10762026/09/10 17:36:41 goose: successfully migrated database to version: 2026090500000010772026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (13.74ms)10782026/09/10 17:36:41 OK 2_object_stats_trigger.sql (4.94ms)10792026/09/10 17:36:41 goose: up to current file version: 210802026/09/10 17:36:41 OK 1_commit_pending_closure.sql (7.07ms)10812026/09/10 17:36:41 OK 20251218171726_add_pins.sql (6.81ms)10822026/09/10 17:36:41 OK 2_object_stats_trigger.sql (3.34ms)10832026/09/10 17:36:41 goose: up to current file version: 21084--- PASS: TestReadProxyConditionalGet (0.61s)1085=== CONT TestMultipartCleanup10862026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (6.04ms)10872026/09/10 17:36:41 OK 20260905000000_add_claims.sql (5.31ms)10882026/09/10 17:36:41 goose: successfully migrated database to version: 2026090500000010892026/09/10 17:36:41 OK 1_commit_pending_closure.sql (3.42ms)10902026-09-10 17:36:41.589 UTC [660] ERROR: relation "goose_db_version" does not exist at character 3610912026-09-10 17:36:41.589 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10922026/09/10 17:36:41 OK 2_object_stats_trigger.sql (2.67ms)10932026/09/10 17:36:41 goose: up to current file version: 21094--- PASS: TestReadProxyNarStreaming (0.64s)1095=== CONT TestMetricsInventory10962026/09/10 17:36:41 OK 20241026095416_initial_model.sql (14.04ms)10972026-09-10 17:36:41.612 UTC [662] ERROR: relation "goose_db_version" does not exist at character 3610982026-09-10 17:36:41.612 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10992026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)11002026/09/10 17:36:41 OK 20251218171726_add_pins.sql (5.49ms)11012026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)11022026-09-10 17:36:41.627 UTC [665] ERROR: relation "goose_db_version" does not exist at character 3611032026-09-10 17:36:41.627 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1104--- PASS: TestReadProxyInvalidPath (0.66s)1105=== CONT TestProxyWriteTimeout1106=== RUN TestProxyWriteTimeout/narinfo1107=== PAUSE TestProxyWriteTimeout/narinfo1108=== RUN TestProxyWriteTimeout/1_GiB_nar1109=== PAUSE TestProxyWriteTimeout/1_GiB_nar1110=== RUN TestProxyWriteTimeout/10_GiB_nar1111=== PAUSE TestProxyWriteTimeout/10_GiB_nar1112=== RUN TestProxyWriteTimeout/unknown_size1113=== PAUSE TestProxyWriteTimeout/unknown_size1114=== CONT TestCacheStatsHandler11152026/09/10 17:36:41 OK 20260905000000_add_claims.sql (6.13ms)11162026/09/10 17:36:41 goose: successfully migrated database to version: 2026090500000011172026/09/10 17:36:41 OK 20241026095416_initial_model.sql (13.03ms)11182026/09/10 17:36:41 OK 1_commit_pending_closure.sql (7.24ms)11192026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (6ms)11202026/09/10 17:36:41 OK 2_object_stats_trigger.sql (2.35ms)11212026/09/10 17:36:41 goose: up to current file version: 211222026/09/10 17:36:41 OK 20251218171726_add_pins.sql (4.79ms)11232026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (11.78ms)11242026/09/10 17:36:41 OK 20241026095416_initial_model.sql (20.46ms)11252026/09/10 17:36:41 OK 20260905000000_add_claims.sql (4.79ms)11262026/09/10 17:36:41 goose: successfully migrated database to version: 2026090500000011272026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (4.85ms)11282026/09/10 17:36:41 OK 1_commit_pending_closure.sql (3.51ms)11292026/09/10 17:36:41 OK 2_object_stats_trigger.sql (2.46ms)11302026/09/10 17:36:41 goose: up to current file version: 211312026-09-10 17:36:41.668 UTC [668] ERROR: relation "goose_db_version" does not exist at character 3611322026-09-10 17:36:41.668 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11332026/09/10 17:36:41 OK 20251218171726_add_pins.sql (5.88ms)1134--- PASS: TestReadRedirectKeepsNarinfoProxied (0.71s)1135=== CONT TestIsValidUploadKey1136=== RUN TestIsValidUploadKey/narinfo1137=== PAUSE TestIsValidUploadKey/narinfo1138=== RUN TestIsValidUploadKey/nar_zst1139=== PAUSE TestIsValidUploadKey/nar_zst1140=== RUN TestIsValidUploadKey/nar_xz1141=== PAUSE TestIsValidUploadKey/nar_xz1142=== RUN TestIsValidUploadKey/nar_plain1143=== PAUSE TestIsValidUploadKey/nar_plain1144=== RUN TestIsValidUploadKey/listing1145=== PAUSE TestIsValidUploadKey/listing1146=== RUN TestIsValidUploadKey/build_log1147=== PAUSE TestIsValidUploadKey/build_log1148=== RUN TestIsValidUploadKey/build_log_home-manager_file1149=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1150=== RUN TestIsValidUploadKey/build_log_plus_in_name1151=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1152=== RUN TestIsValidUploadKey/build_log_question_mark1153=== PAUSE TestIsValidUploadKey/build_log_question_mark1154=== RUN TestIsValidUploadKey/build_log_equals1155=== PAUSE TestIsValidUploadKey/build_log_equals1156=== RUN TestIsValidUploadKey/realisation1157=== PAUSE TestIsValidUploadKey/realisation1158=== RUN TestIsValidUploadKey/realisation_plus_in_output1159=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1160=== RUN TestIsValidUploadKey/nix-cache-info1161=== PAUSE TestIsValidUploadKey/nix-cache-info1162=== RUN TestIsValidUploadKey/index.html1163=== PAUSE TestIsValidUploadKey/index.html1164=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1165=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1166=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1167=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1168=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1169=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1170=== RUN TestIsValidUploadKey/traversal1171=== PAUSE TestIsValidUploadKey/traversal1172=== RUN TestIsValidUploadKey/traversal_nar1173=== PAUSE TestIsValidUploadKey/traversal_nar1174=== RUN TestIsValidUploadKey/absolute1175=== PAUSE TestIsValidUploadKey/absolute1176=== RUN TestIsValidUploadKey/empty_key1177=== PAUSE TestIsValidUploadKey/empty_key1178=== RUN TestIsValidUploadKey/unknown_type1179=== PAUSE TestIsValidUploadKey/unknown_type1180=== CONT TestClaim_FailWithoutKindReleases11812026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (5.51ms)11822026/09/10 17:36:41 INFO Received uploads request method=POST path=/api/pending_closures11832026/09/10 17:36:41 OK 20260905000000_add_claims.sql (5.11ms)11842026/09/10 17:36:41 goose: successfully migrated database to version: 2026090500000011852026-09-10 17:36:41.684 UTC [670] ERROR: relation "goose_db_version" does not exist at character 3611862026-09-10 17:36:41.684 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11872026/09/10 17:36:41 OK 1_commit_pending_closure.sql (3.77ms)11882026/09/10 17:36:41 OK 2_object_stats_trigger.sql (2.84ms)11892026/09/10 17:36:41 goose: up to current file version: 211902026/09/10 17:36:41 OK 20241026095416_initial_model.sql (12.48ms)11912026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (2.92ms)11922026/09/10 17:36:41 OK 20251218171726_add_pins.sql (4.66ms)11932026/09/10 17:36:41 OK 20241026095416_initial_model.sql (11.32ms)11942026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (4.92ms)11952026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (5.14ms)11962026-09-10 17:36:41.708 UTC [672] ERROR: relation "goose_db_version" does not exist at character 3611972026-09-10 17:36:41.708 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11982026/09/10 17:36:41 OK 20260905000000_add_claims.sql (5.3ms)11992026/09/10 17:36:41 goose: successfully migrated database to version: 2026090500000012002026/09/10 17:36:41 OK 20251218171726_add_pins.sql (4.98ms)12012026/09/10 17:36:41 OK 1_commit_pending_closure.sql (3.39ms)12022026/09/10 17:36:41 INFO Received uploads request method=POST path=/api/pending_closures12032026/09/10 17:36:41 OK 2_object_stats_trigger.sql (2.1ms)12042026/09/10 17:36:41 goose: up to current file version: 212052026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (5.06ms)12062026/09/10 17:36:41 OK 20260905000000_add_claims.sql (4.92ms)12072026/09/10 17:36:41 goose: successfully migrated database to version: 2026090500000012082026/09/10 17:36:41 OK 20241026095416_initial_model.sql (10.12ms)12092026/09/10 17:36:41 OK 1_commit_pending_closure.sql (5.47ms)12102026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (4.44ms)12112026/09/10 17:36:41 OK 2_object_stats_trigger.sql (2.57ms)12122026/09/10 17:36:41 goose: up to current file version: 212132026/09/10 17:36:41 OK 20251218171726_add_pins.sql (4.32ms)12142026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (4.64ms)12152026/09/10 17:36:41 OK 20260905000000_add_claims.sql (3.42ms)12162026/09/10 17:36:41 goose: successfully migrated database to version: 2026090500000012172026/09/10 17:36:41 OK 1_commit_pending_closure.sql (1.77ms)12182026/09/10 17:36:41 OK 2_object_stats_trigger.sql (866.85µs)12192026/09/10 17:36:41 goose: up to current file version: 212202026-09-10 17:36:41.750 UTC [673] ERROR: relation "goose_db_version" does not exist at character 3612212026-09-10 17:36:41.750 UTC [673] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12222026/09/10 17:36:41 OK 20241026095416_initial_model.sql (10.08ms)12232026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (1.29ms)12242026/09/10 17:36:41 OK 20251218171726_add_pins.sql (3.49ms)1225--- PASS: TestReadRedirectUsesPublicS3URL (0.81s)1226=== CONT TestClaim_FailWakesWaitersButIsNotRemembered12272026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)12282026/09/10 17:36:41 OK 20260905000000_add_claims.sql (2.71ms)12292026/09/10 17:36:41 goose: successfully migrated database to version: 2026090500000012302026/09/10 17:36:41 OK 1_commit_pending_closure.sql (1.93ms)12312026/09/10 17:36:41 OK 2_object_stats_trigger.sql (965.47µs)12322026/09/10 17:36:41 goose: up to current file version: 212332026-09-10 17:36:41.852 UTC [676] ERROR: relation "goose_db_version" does not exist at character 3612342026-09-10 17:36:41.852 UTC [676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12352026/09/10 17:36:41 OK 20241026095416_initial_model.sql (16.18ms)12362026/09/10 17:36:41 OK 20251210153512_drop_unused_gin_index.sql (1.71ms)12372026/09/10 17:36:41 OK 20251218171726_add_pins.sql (3.43ms)12382026/09/10 17:36:41 OK 20260628120000_add_object_size_and_stats.sql (3.98ms)12392026/09/10 17:36:41 OK 20260905000000_add_claims.sql (3.13ms)12402026/09/10 17:36:41 goose: successfully migrated database to version: 2026090500000012412026/09/10 17:36:41 OK 1_commit_pending_closure.sql (2.27ms)12422026/09/10 17:36:41 OK 2_object_stats_trigger.sql (1.28ms)12432026/09/10 17:36:41 goose: up to current file version: 212442026/09/10 17:36:41 INFO Received uploads request method=POST path=/api/pending_closures12452026/09/10 17:36:42 INFO Received uploads request method=POST path=/api/pending_closures1246--- PASS: TestReadProxyHead (1.06s)1247=== CONT TestClaim_StaleHeartbeatStolen12482026/09/10 17:36:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1249--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.08s)1250=== CONT TestService_Rustfstest12512026/09/10 17:36:42 INFO Received uploads request method=POST path=/api/pending_closures12522026-09-10 17:36:42.107 UTC [684] ERROR: relation "goose_db_version" does not exist at character 3612532026-09-10 17:36:42.107 UTC [684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12542026/09/10 17:36:42 OK 20241026095416_initial_model.sql (18.15ms)1255--- PASS: TestReadProxy404 (1.16s)1256=== CONT TestClaim_HolderDisconnectKeepsClaim12572026/09/10 17:36:42 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)12582026/09/10 17:36:42 OK 20251218171726_add_pins.sql (4.07ms)12592026/09/10 17:36:42 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)12602026-09-10 17:36:42.143 UTC [686] ERROR: relation "goose_db_version" does not exist at character 3612612026-09-10 17:36:42.143 UTC [686] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12622026/09/10 17:36:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12632026/09/10 17:36:42 OK 20260905000000_add_claims.sql (4.63ms)12642026/09/10 17:36:42 goose: successfully migrated database to version: 2026090500000012652026/09/10 17:36:42 OK 1_commit_pending_closure.sql (2.83ms)12662026/09/10 17:36:42 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YmVjZTY3ZDUtYjI4Yi00MmRmLTg3YWMtOTUwMzhhNDc4MjEzLjc3NWJiM2E4LTk4ZTktNDQwNi05ZDllLTJjZjIyZmQ5NWZkZngxNzg5MDYxODAyMTEyOTE3ODEy12672026/09/10 17:36:42 OK 2_object_stats_trigger.sql (2.52ms)12682026/09/10 17:36:42 goose: up to current file version: 21269--- PASS: TestReadProxyDisabled (1.20s)1270=== CONT TestGCTaskStore_DeduplicateSameParams1271--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1272=== CONT TestClaim_GCMarkedOutputCountsAsAbsent12732026/09/10 17:36:42 OK 20241026095416_initial_model.sql (12.05ms)12742026/09/10 17:36:42 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YmVjZTY3ZDUtYjI4Yi00MmRmLTg3YWMtOTUwMzhhNDc4MjEzLjc3NWJiM2E4LTk4ZTktNDQwNi05ZDllLTJjZjIyZmQ5NWZkZngxNzg5MDYxODAyMTEyOTE3ODEy parts=11275--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.20s)1276=== CONT TestClaim_BuildWaitComplete12772026/09/10 17:36:42 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)12782026/09/10 17:36:42 OK 20251218171726_add_pins.sql (3.83ms)12792026/09/10 17:36:42 OK 20260628120000_add_object_size_and_stats.sql (3.08ms)12802026/09/10 17:36:42 OK 20260905000000_add_claims.sql (5.33ms)12812026/09/10 17:36:42 goose: successfully migrated database to version: 2026090500000012822026/09/10 17:36:42 OK 1_commit_pending_closure.sql (4.66ms)12832026/09/10 17:36:42 OK 2_object_stats_trigger.sql (2.96ms)12842026/09/10 17:36:42 goose: up to current file version: 212852026-09-10 17:36:42.210 UTC [692] ERROR: relation "goose_db_version" does not exist at character 3612862026-09-10 17:36:42.210 UTC [692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12872026/09/10 17:36:42 OK 20241026095416_initial_model.sql (12.06ms)12882026/09/10 17:36:42 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)12892026-09-10 17:36:42.248 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3612902026-09-10 17:36:42.248 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12912026/09/10 17:36:42 OK 20251218171726_add_pins.sql (7.07ms)12922026/09/10 17:36:42 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)12932026/09/10 17:36:42 OK 20260905000000_add_claims.sql (4.3ms)12942026/09/10 17:36:42 goose: successfully migrated database to version: 2026090500000012952026/09/10 17:36:42 OK 1_commit_pending_closure.sql (3.09ms)12962026/09/10 17:36:42 OK 2_object_stats_trigger.sql (1.46ms)12972026/09/10 17:36:42 goose: up to current file version: 212982026-09-10 17:36:42.265 UTC [694] ERROR: relation "goose_db_version" does not exist at character 3612992026-09-10 17:36:42.265 UTC [694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13002026/09/10 17:36:42 OK 20241026095416_initial_model.sql (10.9ms)13012026/09/10 17:36:42 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)13022026/09/10 17:36:42 OK 20251218171726_add_pins.sql (3ms)13032026/09/10 17:36:42 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)13042026/09/10 17:36:42 OK 20260905000000_add_claims.sql (4.15ms)13052026/09/10 17:36:42 goose: successfully migrated database to version: 2026090500000013062026/09/10 17:36:42 OK 20241026095416_initial_model.sql (9.93ms)13072026/09/10 17:36:42 OK 20251210153512_drop_unused_gin_index.sql (1.32ms)13082026/09/10 17:36:42 OK 1_commit_pending_closure.sql (2.17ms)13092026/09/10 17:36:42 OK 2_object_stats_trigger.sql (1.16ms)13102026/09/10 17:36:42 goose: up to current file version: 213112026/09/10 17:36:42 OK 20251218171726_add_pins.sql (2.6ms)13122026/09/10 17:36:42 OK 20260628120000_add_object_size_and_stats.sql (3.31ms)13132026/09/10 17:36:42 OK 20260905000000_add_claims.sql (2.82ms)13142026/09/10 17:36:42 goose: successfully migrated database to version: 2026090500000013152026/09/10 17:36:42 OK 1_commit_pending_closure.sql (1.97ms)13162026/09/10 17:36:42 OK 2_object_stats_trigger.sql (978.03µs)13172026/09/10 17:36:42 goose: up to current file version: 213182026/09/10 17:36:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13192026/09/10 17:36:42 INFO Received uploads request method=POST path=/api/pending_closures13202026/09/10 17:36:42 INFO Received uploads request method=POST path=/api/pending_closures13212026/09/10 17:36:42 INFO Received uploads request method=POST path=/api/pending_closures13222026/09/10 17:36:42 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YmVjZTY3ZDUtYjI4Yi00MmRmLTg3YWMtOTUwMzhhNDc4MjEzLjllZTQ3MWNhLTU3NGQtNGI3My05MTBhLTQyNGU2MTA1OTdlZXgxNzg5MDYxODAxOTIzMzAyOTcw parts=1013232026/09/10 17:36:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13242026/09/10 17:36:42 INFO Completed upload id=113252026/09/10 17:36:42 INFO Received uploads request method=POST path=/api/pending_closures13262026/09/10 17:36:42 INFO Received uploads request method=POST path=/api/pending_closures13272026/09/10 17:36:42 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13282026/09/10 17:36:42 WARN Found objects in DB but missing from S3, will re-upload count=11329--- PASS: TestService_verifyS3Integrity (1.52s)1330=== CONT TestGCTaskStore_StartNew1331--- PASS: TestGCTaskStore_StartNew (0.00s)1332=== CONT TestClaim_TooManyStreams13332026/09/10 17:36:42 INFO Received cleanup request method=DELETE path=/api/pending_closures13342026/09/10 17:36:42 INFO Aborted multipart uploads count=013352026/09/10 17:36:42 INFO Received uploads request method=POST path=/api/pending_closures13362026/09/10 17:36:42 INFO Received cleanup request method=DELETE path=/api/pending_closures13372026/09/10 17:36:42 INFO Aborted multipart uploads count=113382026/09/10 17:36:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13392026-09-10 17:36:42.526 UTC [635] ERROR: Closure does not exist: id=113402026-09-10 17:36:42.526 UTC [635] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE13412026-09-10 17:36:42.526 UTC [635] STATEMENT: -- name: CommitPendingClosure :exec1342 SELECT commit_pending_closure($1::bigint)1343 1344--- PASS: TestService_cleanupPendingClosuresHandler (1.56s)1345=== CONT TestGCMetrics13462026/09/10 17:36:42 WARN readiness check failed error="closed pool"1347--- PASS: TestService_readinessHandler (1.22s)1348=== CONT TestClientIntegration13492026-09-10 17:36:42.557 UTC [720] ERROR: relation "goose_db_version" does not exist at character 3613502026-09-10 17:36:42.557 UTC [720] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1351--- PASS: TestService_healthCheckHandler (1.20s)1352=== CONT TestClaim_StreamsThroughServer13532026/09/10 17:36:42 OK 20241026095416_initial_model.sql (12.87ms)13542026/09/10 17:36:42 OK 20251210153512_drop_unused_gin_index.sql (11.07ms)13552026/09/10 17:36:42 OK 20251218171726_add_pins.sql (6.01ms)13562026/09/10 17:36:42 OK 20260628120000_add_object_size_and_stats.sql (6.2ms)13572026/09/10 17:36:42 OK 20260905000000_add_claims.sql (4.3ms)13582026/09/10 17:36:42 goose: successfully migrated database to version: 2026090500000013592026/09/10 17:36:42 OK 1_commit_pending_closure.sql (3.23ms)13602026/09/10 17:36:42 OK 2_object_stats_trigger.sql (1.87ms)13612026/09/10 17:36:42 goose: up to current file version: 213622026-09-10 17:36:42.617 UTC [723] ERROR: relation "goose_db_version" does not exist at character 3613632026-09-10 17:36:42.617 UTC [723] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13642026-09-10 17:36:42.618 UTC [724] ERROR: relation "goose_db_version" does not exist at character 3613652026-09-10 17:36:42.618 UTC [724] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13662026/09/10 17:36:42 OK 20241026095416_initial_model.sql (11.47ms)13672026/09/10 17:36:42 OK 20241026095416_initial_model.sql (12.75ms)13682026/09/10 17:36:42 OK 20251210153512_drop_unused_gin_index.sql (3.27ms)13692026/09/10 17:36:42 OK 20251210153512_drop_unused_gin_index.sql (1.2ms)13702026/09/10 17:36:42 OK 20251218171726_add_pins.sql (4.21ms)13712026/09/10 17:36:42 OK 20251218171726_add_pins.sql (3.66ms)13722026-09-10 17:36:42.645 UTC [725] ERROR: relation "goose_db_version" does not exist at character 3613732026-09-10 17:36:42.645 UTC [725] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13742026/09/10 17:36:42 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)13752026/09/10 17:36:42 OK 20260628120000_add_object_size_and_stats.sql (4.23ms)13762026/09/10 17:36:42 OK 20260905000000_add_claims.sql (3.45ms)13772026/09/10 17:36:42 goose: successfully migrated database to version: 2026090500000013782026/09/10 17:36:42 OK 20260905000000_add_claims.sql (3.48ms)13792026/09/10 17:36:42 goose: successfully migrated database to version: 2026090500000013802026/09/10 17:36:42 OK 1_commit_pending_closure.sql (2.03ms)13812026/09/10 17:36:42 OK 1_commit_pending_closure.sql (2.47ms)13822026/09/10 17:36:42 OK 2_object_stats_trigger.sql (963.77µs)13832026/09/10 17:36:42 goose: up to current file version: 213842026/09/10 17:36:42 OK 2_object_stats_trigger.sql (1.22ms)13852026/09/10 17:36:42 goose: up to current file version: 213862026/09/10 17:36:42 OK 20241026095416_initial_model.sql (11.27ms)13872026/09/10 17:36:42 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)13882026/09/10 17:36:42 OK 20251218171726_add_pins.sql (3.17ms)13892026/09/10 17:36:42 OK 20260628120000_add_object_size_and_stats.sql (3.63ms)13902026/09/10 17:36:42 OK 20260905000000_add_claims.sql (2.93ms)13912026/09/10 17:36:42 goose: successfully migrated database to version: 2026090500000013922026/09/10 17:36:42 OK 1_commit_pending_closure.sql (1.9ms)13932026/09/10 17:36:42 OK 2_object_stats_trigger.sql (827.45µs)13942026/09/10 17:36:42 goose: up to current file version: 21395=== NAME TestNARDeduplicationMetadataUploadBug1396 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug4084795730/001/store/xqi2nk5bv5v56nwycdp991ppz3axf58b-file1.txt1397--- PASS: TestResurrectedObjectNotDeleted (1.54s)1398=== CONT TestClaim_InputsTouched13992026/09/10 17:36:43 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1400--- PASS: TestObjectStatsTrigger (1.50s)1401=== CONT TestGCBugBareHashReferences14022026/09/10 17:36:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14032026/09/10 17:36:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1404--- PASS: TestService_NativeMTLS (1.49s)1405=== CONT TestClientErrorHandling1406=== RUN TestClientErrorHandling/InvalidStorePath1407=== PAUSE TestClientErrorHandling/InvalidStorePath1408=== RUN TestClientErrorHandling/InvalidAuthToken1409=== PAUSE TestClientErrorHandling/InvalidAuthToken1410=== RUN TestClientErrorHandling/ServerNotAvailable1411=== PAUSE TestClientErrorHandling/ServerNotAvailable1412=== CONT TestClaim_TwoInstances14132026-09-10 17:36:43.037 UTC [786] ERROR: relation "goose_db_version" does not exist at character 3614142026-09-10 17:36:43.037 UTC [786] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14152026/09/10 17:36:43 INFO Received uploads request method=POST path=/api/pending_closures14162026/09/10 17:36:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14172026/09/10 17:36:43 INFO Uploading xqi2nk5bv5v56nwycdp991ppz3axf58b-file1.txt (160B)14182026/09/10 17:36:43 OK 20241026095416_initial_model.sql (12.16ms)14192026/09/10 17:36:43 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14202026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (15.43ms)14212026/09/10 17:36:43 WARN Failed to register uploaded object key=xqi2nk5bv5v56nwycdp991ppz3axf58b.ls error="server returned 404: 404 page not found\n"14222026/09/10 17:36:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14232026/09/10 17:36:43 INFO Signed narinfos id=1 count=114242026/09/10 17:36:43 INFO Uploading 1 narinfos14252026/09/10 17:36:43 INFO Received uploads request method=POST path=/api/pending_closures14262026/09/10 17:36:43 WARN Failed to register uploaded object key=xqi2nk5bv5v56nwycdp991ppz3axf58b.narinfo error="server returned 404: 404 page not found\n"14272026/09/10 17:36:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14282026/09/10 17:36:43 OK 20251218171726_add_pins.sql (13.51ms)14292026/09/10 17:36:43 INFO Completed upload id=114302026/09/10 17:36:43 INFO Upload complete. (124ms)14312026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (5.74ms)1432=== NAME TestNARDeduplicationMetadataUploadBug1433 metadata_upload_test.go:54: Retrieved narinfo from S3:1434 StorePath: /build/TestNARDeduplicationMetadataUploadBug4084795730/001/store/xqi2nk5bv5v56nwycdp991ppz3axf58b-file1.txt1435 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1436 Compression: zstd1437 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1438 NarSize: 1601439 References: 1440 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf14412026/09/10 17:36:43 OK 20260905000000_add_claims.sql (4.44ms)14422026/09/10 17:36:43 goose: successfully migrated database to version: 202609050000001443 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1444 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1445 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14462026/09/10 17:36:43 OK 1_commit_pending_closure.sql (2.88ms)14472026/09/10 17:36:43 OK 2_object_stats_trigger.sql (1.11ms)14482026/09/10 17:36:43 goose: up to current file version: 214492026-09-10 17:36:43.109 UTC [805] ERROR: relation "goose_db_version" does not exist at character 3614502026-09-10 17:36:43.109 UTC [805] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14512026-09-10 17:36:43.113 UTC [806] ERROR: relation "goose_db_version" does not exist at character 3614522026-09-10 17:36:43.113 UTC [806] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14532026/09/10 17:36:43 OK 20241026095416_initial_model.sql (9.7ms)14542026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (1.39ms)14552026/09/10 17:36:43 OK 20251218171726_add_pins.sql (4.18ms)14562026/09/10 17:36:43 OK 20241026095416_initial_model.sql (10.47ms)1457--- PASS: TestMetricsInventory (1.52s)1458=== CONT TestResolveDBConnectionString1459=== RUN TestResolveDBConnectionString/flag_wins1460=== PAUSE TestResolveDBConnectionString/flag_wins1461=== RUN TestResolveDBConnectionString/file_when_flag_empty1462=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1463=== RUN TestResolveDBConnectionString/missing_file_is_an_error1464=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1465=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1466=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1467=== RUN TestResolveDBConnectionString/nothing_configured1468=== PAUSE TestResolveDBConnectionString/nothing_configured1469=== CONT TestClientCADerivations14702026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)14712026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (4.39ms)14722026/09/10 17:36:43 OK 20251218171726_add_pins.sql (3.13ms)1473=== NAME TestNARDeduplicationMetadataUploadBug1474 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug4084795730/001/store/11q749qisy3ffr2l963vxg1s66h6fhdm-file2.txt14752026/09/10 17:36:43 OK 20260905000000_add_claims.sql (4.63ms)14762026/09/10 17:36:43 goose: successfully migrated database to version: 2026090500000014772026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)14782026/09/10 17:36:43 OK 1_commit_pending_closure.sql (2.5ms)14792026/09/10 17:36:43 OK 20260905000000_add_claims.sql (4.86ms)14802026/09/10 17:36:43 goose: successfully migrated database to version: 2026090500000014812026/09/10 17:36:43 OK 2_object_stats_trigger.sql (3.29ms)14822026/09/10 17:36:43 goose: up to current file version: 214832026/09/10 17:36:43 OK 1_commit_pending_closure.sql (3.77ms)1484--- PASS: TestCacheStatsHandler (1.52s)1485=== CONT TestClientWithDependencies14862026/09/10 17:36:43 OK 2_object_stats_trigger.sql (4.1ms)14872026/09/10 17:36:43 goose: up to current file version: 214882026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"14892026/09/10 17:36:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14902026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"1491--- PASS: TestClaim_FailWithoutKindReleases (1.51s)1492=== CONT TestClientMultipleUploads14932026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"14942026/09/10 17:36:43 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YmVjZTY3ZDUtYjI4Yi00MmRmLTg3YWMtOTUwMzhhNDc4MjEzLmE3OWYwYTQ1LWJjY2EtNGZmNi1hMjBlLTA5NTdkMTRjNjY1M3gxNzg5MDYxODAxNDU5MDgzNzQy parts=1214952026/09/10 17:36:43 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14962026/09/10 17:36:43 INFO Received uploads request method=POST path=/api/pending_closures14972026/09/10 17:36:43 INFO Received cleanup request method=DELETE path=/api/pending_closures1498--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.24s)1499=== CONT TestService_AuthMiddleware_OIDC15002026-09-10 17:36:43.204 UTC [867] ERROR: relation "goose_db_version" does not exist at character 3615012026-09-10 17:36:43.204 UTC [867] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15022026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"15032026/09/10 17:36:43 INFO Aborted multipart uploads count=115042026/09/10 17:36:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39639/oidc15052026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"1506--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (1.44s)1507=== CONT TestPinProtectsFromGC1508--- PASS: TestMultipartCleanup (1.64s)1509=== CONT TestCacheConfigHandler1510=== RUN TestCacheConfigHandler/full_config,_no_issuer1511=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1512=== RUN TestCacheConfigHandler/no_cache_url_configured1513=== PAUSE TestCacheConfigHandler/no_cache_url_configured1514=== RUN TestCacheConfigHandler/no_signing_keys1515=== PAUSE TestCacheConfigHandler/no_signing_keys1516=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1517=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1518=== CONT TestService_ReadScope_PublicByDefault15192026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"15202026/09/10 17:36:43 OK 20241026095416_initial_model.sql (19.58ms)15212026/09/10 17:36:43 INFO Received uploads request method=POST path=/api/pending_closures15222026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (3.46ms)15232026/09/10 17:36:43 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15242026-09-10 17:36:43.240 UTC [893] ERROR: relation "goose_db_version" does not exist at character 3615252026-09-10 17:36:43.240 UTC [893] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15262026/09/10 17:36:43 OK 20251218171726_add_pins.sql (8.02ms)15272026/09/10 17:36:43 WARN Failed to register uploaded object key=11q749qisy3ffr2l963vxg1s66h6fhdm.ls error="server returned 404: 404 page not found\n"15282026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"15292026/09/10 17:36:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15302026/09/10 17:36:43 INFO Signed narinfos id=2 count=115312026/09/10 17:36:43 INFO Uploading 1 narinfos1532--- PASS: TestClaim_StaleHeartbeatStolen (1.22s)1533=== CONT TestService_RequireScope_OIDC15342026/09/10 17:36:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35247/oidc15352026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (8.62ms)15362026/09/10 17:36:43 WARN Failed to register uploaded object key=11q749qisy3ffr2l963vxg1s66h6fhdm.narinfo error="server returned 404: 404 page not found\n"15372026/09/10 17:36:43 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15382026/09/10 17:36:43 INFO Completed upload id=215392026/09/10 17:36:43 INFO Upload complete. (88ms)1540=== NAME TestNARDeduplicationMetadataUploadBug1541 metadata_upload_test.go:76: Retrieved narinfo from S3:1542 StorePath: /build/TestNARDeduplicationMetadataUploadBug4084795730/001/store/11q749qisy3ffr2l963vxg1s66h6fhdm-file2.txt1543 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1544 Compression: zstd1545 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1546 NarSize: 1601547 References: 1548 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf15492026/09/10 17:36:43 OK 20260905000000_add_claims.sql (7.81ms)15502026/09/10 17:36:43 goose: successfully migrated database to version: 2026090500000015512026/09/10 17:36:43 OK 20241026095416_initial_model.sql (11.83ms)1552 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1553 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1554 {"version":1,"root":{"type":"regular","size":44}}15552026/09/10 17:36:43 OK 1_commit_pending_closure.sql (4.5ms)15562026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (4.85ms)1557--- PASS: TestNARDeduplicationMetadataUploadBug (1.85s)1558=== CONT TestService_AuthMiddleware_MTLSProxyHeader15592026/09/10 17:36:43 OK 2_object_stats_trigger.sql (3.61ms)15602026/09/10 17:36:43 goose: up to current file version: 215612026/09/10 17:36:43 OK 20251218171726_add_pins.sql (4.53ms)15622026-09-10 17:36:43.275 UTC [896] ERROR: relation "goose_db_version" does not exist at character 3615632026-09-10 17:36:43.275 UTC [896] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15642026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (7.12ms)15652026/09/10 17:36:43 OK 20260905000000_add_claims.sql (4.17ms)15662026/09/10 17:36:43 goose: successfully migrated database to version: 2026090500000015672026/09/10 17:36:43 OK 1_commit_pending_closure.sql (3.53ms)15682026/09/10 17:36:43 OK 2_object_stats_trigger.sql (10.47ms)15692026/09/10 17:36:43 goose: up to current file version: 215702026/09/10 17:36:43 OK 20241026095416_initial_model.sql (13.98ms)15712026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (2.83ms)1572--- PASS: TestService_Rustfstest (1.25s)1573=== CONT TestService_ReadAuthMiddleware15742026-09-10 17:36:43.307 UTC [899] ERROR: relation "goose_db_version" does not exist at character 3615752026-09-10 17:36:43.307 UTC [899] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15762026/09/10 17:36:43 OK 20251218171726_add_pins.sql (7.43ms)15772026-09-10 17:36:43.308 UTC [900] ERROR: relation "goose_db_version" does not exist at character 3615782026-09-10 17:36:43.308 UTC [900] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15792026-09-10 17:36:43.312 UTC [902] ERROR: relation "goose_db_version" does not exist at character 3615802026-09-10 17:36:43.312 UTC [902] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15812026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (6ms)15822026/09/10 17:36:43 OK 20260905000000_add_claims.sql (5.05ms)15832026/09/10 17:36:43 goose: successfully migrated database to version: 2026090500000015842026/09/10 17:36:43 OK 1_commit_pending_closure.sql (3.81ms)15852026/09/10 17:36:43 OK 2_object_stats_trigger.sql (2.58ms)15862026/09/10 17:36:43 goose: up to current file version: 215872026/09/10 17:36:43 OK 20241026095416_initial_model.sql (13.1ms)15882026/09/10 17:36:43 OK 20241026095416_initial_model.sql (14.62ms)15892026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (3.11ms)15902026/09/10 17:36:43 OK 20241026095416_initial_model.sql (13.63ms)15912026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (3.27ms)15922026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (3.38ms)15932026/09/10 17:36:43 OK 20251218171726_add_pins.sql (5.94ms)15942026/09/10 17:36:43 OK 20251218171726_add_pins.sql (5.77ms)15952026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"15962026/09/10 17:36:43 OK 20251218171726_add_pins.sql (6.85ms)15972026-09-10 17:36:43.344 UTC [904] ERROR: relation "goose_db_version" does not exist at character 3615982026-09-10 17:36:43.344 UTC [904] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15992026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (6.47ms)16002026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (7.88ms)16012026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (4.94ms)1602=== NAME TestOrphanedObjectsGC1603 orphaned_objects_gc_test.go:290: GC Test Summary:16042026/09/10 17:36:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1605 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1606 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1607 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1608 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1609 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1610--- PASS: TestOrphanedObjectsGC (1.84s)1611=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16122026/09/10 17:36:43 OK 20260905000000_add_claims.sql (4.77ms)16132026/09/10 17:36:43 goose: successfully migrated database to version: 2026090500000016142026/09/10 17:36:43 OK 20260905000000_add_claims.sql (4.74ms)16152026/09/10 17:36:43 goose: successfully migrated database to version: 2026090500000016162026/09/10 17:36:43 OK 20260905000000_add_claims.sql (4.15ms)16172026/09/10 17:36:43 goose: successfully migrated database to version: 2026090500000016182026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"16192026/09/10 17:36:43 OK 1_commit_pending_closure.sql (4.16ms)16202026/09/10 17:36:43 OK 1_commit_pending_closure.sql (3.99ms)16212026/09/10 17:36:43 OK 1_commit_pending_closure.sql (4ms)16222026/09/10 17:36:43 OK 2_object_stats_trigger.sql (1.92ms)16232026/09/10 17:36:43 goose: up to current file version: 216242026/09/10 17:36:43 OK 2_object_stats_trigger.sql (3.07ms)16252026/09/10 17:36:43 goose: up to current file version: 216262026/09/10 17:36:43 OK 2_object_stats_trigger.sql (2.17ms)16272026/09/10 17:36:43 goose: up to current file version: 216282026-09-10 17:36:43.360 UTC [907] ERROR: relation "goose_db_version" does not exist at character 3616292026-09-10 17:36:43.360 UTC [907] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16302026/09/10 17:36:43 OK 20241026095416_initial_model.sql (10.03ms)16312026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (3.52ms)16322026/09/10 17:36:43 OK 20251218171726_add_pins.sql (4.27ms)16332026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)16342026/09/10 17:36:43 INFO Received uploads request method=POST path=/api/pending_closures16352026/09/10 17:36:43 OK 20260905000000_add_claims.sql (4.59ms)16362026/09/10 17:36:43 goose: successfully migrated database to version: 2026090500000016372026/09/10 17:36:43 OK 20241026095416_initial_model.sql (12.36ms)16382026/09/10 17:36:43 OK 1_commit_pending_closure.sql (3.69ms)16392026/09/10 17:36:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YmVjZTY3ZDUtYjI4Yi00MmRmLTg3YWMtOTUwMzhhNDc4MjEzLmIxY2JhZmQyLTJlMWUtNGExYi05MmY0LTQ2MzkxM2UxYzk2ZHgxNzg5MDYxODAxOTk0NTY1Njk1 parts=1216402026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (3ms)16412026-09-10 17:36:43.384 UTC [910] ERROR: relation "goose_db_version" does not exist at character 3616422026-09-10 17:36:43.384 UTC [910] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16432026/09/10 17:36:43 OK 2_object_stats_trigger.sql (2.67ms)16442026/09/10 17:36:43 goose: up to current file version: 21645--- PASS: TestRedundantMultipartUpload (2.42s)1646=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16472026/09/10 17:36:43 INFO Received uploads request method=POST path=/1648=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16492026/09/10 17:36:43 INFO Received complete multipart upload request method=POST path=/1650=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16512026/09/10 17:36:43 INFO Received uploads request method=POST path=/1652=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16532026/09/10 17:36:43 INFO Received request for more parts method=POST path=/1654=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16552026/09/10 17:36:43 INFO Received uploads request method=POST path=/1656--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1657 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1658 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1659 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1660 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)16612026/09/10 17:36:43 OK 20251218171726_add_pins.sql (5.99ms)16622026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (4.75ms)16632026/09/10 17:36:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16642026/09/10 17:36:43 OK 20260905000000_add_claims.sql (12.17ms)16652026/09/10 17:36:43 goose: successfully migrated database to version: 2026090500000016662026/09/10 17:36:43 OK 20241026095416_initial_model.sql (16.71ms)16672026/09/10 17:36:43 OK 1_commit_pending_closure.sql (4.52ms)16682026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (3.19ms)16692026/09/10 17:36:43 OK 2_object_stats_trigger.sql (1.35ms)16702026/09/10 17:36:43 goose: up to current file version: 216712026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"16722026/09/10 17:36:43 OK 20251218171726_add_pins.sql (5.04ms)16732026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)16742026/09/10 17:36:43 OK 20260905000000_add_claims.sql (4.24ms)16752026/09/10 17:36:43 goose: successfully migrated database to version: 2026090500000016762026/09/10 17:36:43 OK 1_commit_pending_closure.sql (2.09ms)16772026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"16782026/09/10 17:36:43 OK 2_object_stats_trigger.sql (974.99µs)16792026/09/10 17:36:43 goose: up to current file version: 216802026-09-10 17:36:43.429 UTC [912] ERROR: relation "goose_db_version" does not exist at character 3616812026-09-10 17:36:43.429 UTC [912] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16822026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"16832026/09/10 17:36:43 INFO Received uploads request method=POST path=/api/pending_closures16842026/09/10 17:36:43 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YmVjZTY3ZDUtYjI4Yi00MmRmLTg3YWMtOTUwMzhhNDc4MjEzLjM4NGU2ZDY1LTYyOTktNGEzYi05NmUxLTZiYTZhOTJmMmIyYXgxNzg5MDYxODAyNDc1MzE5ODA4 parts=1016852026/09/10 17:36:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16862026/09/10 17:36:43 INFO Completed upload id=116872026/09/10 17:36:43 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016882026/09/10 17:36:43 INFO Received uploads request method=POST path=/api/pending_closures16892026/09/10 17:36:43 OK 20241026095416_initial_model.sql (8.75ms)16902026/09/10 17:36:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures16912026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (1.24ms)16922026/09/10 17:36:43 OK 20251218171726_add_pins.sql (3.96ms)16932026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (2.24ms)16942026/09/10 17:36:43 INFO Aborted multipart uploads count=016952026/09/10 17:36:43 OK 20260905000000_add_claims.sql (2.98ms)16962026/09/10 17:36:43 goose: successfully migrated database to version: 2026090500000016972026/09/10 17:36:43 OK 1_commit_pending_closure.sql (2.12ms)16982026/09/10 17:36:43 OK 2_object_stats_trigger.sql (896.43µs)16992026/09/10 17:36:43 goose: up to current file version: 217002026/09/10 17:36:43 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=017012026/09/10 17:36:43 INFO Vacuumed table table=pending_closures17022026/09/10 17:36:43 INFO Vacuumed table table=pending_objects17032026/09/10 17:36:43 INFO Vacuumed table table=multipart_uploads17042026/09/10 17:36:43 INFO Vacuumed table table=closures17052026/09/10 17:36:43 INFO Vacuumed table table=objects17062026/09/10 17:36:43 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001707--- PASS: TestService_createPendingClosureHandler (2.53s)1708=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17092026/09/10 17:36:43 INFO Received request for more parts method=POST path=/1710=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17112026/09/10 17:36:43 INFO Received complete multipart upload request method=POST path=/1712=== CONT TestIsValidCachePath/narinfo1713=== CONT TestIsValidCachePath/random_path1714=== CONT TestIsValidCachePath/invalid_char_u1715=== CONT TestIsValidCachePath/invalid_char_e1716=== CONT TestIsValidCachePath/traversal_in_middle1717=== CONT TestIsValidCachePath/traversal_parent1718=== CONT TestIsValidCachePath/index.html1719=== CONT TestIsValidCachePath/nix-cache-info1720=== CONT TestIsValidCachePath/realisation1721=== CONT TestIsValidCachePath/log1722=== CONT TestIsValidCachePath/empty1723=== CONT TestIsValidCachePath/ls1724=== CONT TestIsValidCachePath/nar_zst1725=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1726=== CONT TestIsValidCachePath/wrong_extension1727=== CONT TestIsValidCachePath/short_hash1728=== CONT TestIsValidCachePath/nar_xz1729=== CONT TestIsValidCachePath/nar_uncompressed1730=== CONT TestIsValidCachePath/nar_bz21731=== CONT TestIsValidCachePath/leading_slash1732=== CONT TestParseSingleRange/none1733=== CONT TestParseSingleRange/open-ended1734=== CONT TestParseSingleRange/malformed_both_empty1735=== CONT TestParseSingleRange/start_far_past_EOF1736=== CONT TestParseSingleRange/closed1737=== CONT TestParseSingleRange/suffix1738=== CONT TestParseSingleRange/malformed_end_before_start1739--- PASS: TestIsValidCachePath (0.00s)1740 --- PASS: TestIsValidCachePath/narinfo (0.00s)1741 --- PASS: TestIsValidCachePath/random_path (0.00s)1742 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1743 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1744 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1745 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1746 --- PASS: TestIsValidCachePath/index.html (0.00s)1747 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1748 --- PASS: TestIsValidCachePath/realisation (0.00s)1749 --- PASS: TestIsValidCachePath/log (0.00s)1750 --- PASS: TestIsValidCachePath/empty (0.00s)1751 --- PASS: TestIsValidCachePath/ls (0.00s)1752 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1753 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1754 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1755 --- PASS: TestIsValidCachePath/short_hash (0.00s)1756 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1757 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1758 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1759 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1760=== CONT TestParseSingleRange/end_clamped_to_size1761=== CONT TestParseSingleRange/start_past_EOF1762=== CONT TestParseSingleRange/multi-range_ignored1763=== CONT TestParseSingleRange/single_byte1764=== CONT TestParseSingleRange/malformed_no_dash1765=== CONT TestParseSingleRange/suffix_exceeds_size1766=== CONT TestParseSingleRange/unknown_unit1767--- PASS: TestParseSingleRange (0.00s)1768 --- PASS: TestParseSingleRange/none (0.00s)1769 --- PASS: TestParseSingleRange/open-ended (0.00s)1770 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1771 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1772 --- PASS: TestParseSingleRange/closed (0.00s)1773 --- PASS: TestParseSingleRange/suffix (0.00s)1774 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1775 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1776 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1777 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1778 --- PASS: TestParseSingleRange/single_byte (0.00s)1779 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1780 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1781 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1782=== CONT TestServerTLSConfig/no_client_CA1783=== CONT TestServerTLSConfig/not_a_PEM_file1784=== CONT TestServerTLSConfig/missing_CA_file1785=== CONT TestProxyWriteTimeout/narinfo1786=== CONT TestProxyWriteTimeout/10_GiB_nar1787=== CONT TestProxyWriteTimeout/unknown_size1788=== CONT TestProxyWriteTimeout/1_GiB_nar1789=== CONT TestIsValidUploadKey/narinfo1790=== CONT TestIsValidUploadKey/unknown_type1791=== CONT TestIsValidUploadKey/empty_key1792=== CONT TestIsValidUploadKey/absolute1793=== CONT TestIsValidUploadKey/traversal_nar1794=== CONT TestIsValidUploadKey/traversal1795=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1796=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1797=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1798=== CONT TestIsValidUploadKey/index.html1799=== CONT TestIsValidUploadKey/nix-cache-info1800=== CONT TestIsValidUploadKey/realisation_plus_in_output1801=== CONT TestIsValidUploadKey/realisation1802=== CONT TestIsValidUploadKey/build_log_equals1803=== CONT TestIsValidUploadKey/listing1804=== CONT TestIsValidUploadKey/nar_plain1805--- PASS: TestServerTLSConfig (0.00s)1806 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1807 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1808 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1809=== CONT TestIsValidUploadKey/nar_xz1810=== CONT TestIsValidUploadKey/nar_zst1811=== CONT TestIsValidUploadKey/build_log_plus_in_name1812=== CONT TestIsValidUploadKey/build_log_question_mark1813=== CONT TestIsValidUploadKey/build_log1814--- PASS: TestProxyWriteTimeout (0.00s)1815 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1816 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1817 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1818 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1819=== CONT TestIsValidUploadKey/build_log_home-manager_file1820=== CONT TestClientErrorHandling/InvalidStorePath1821--- PASS: TestIsValidUploadKey (0.00s)1822 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1823 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1824 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1825 --- PASS: TestIsValidUploadKey/absolute (0.00s)1826 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1827 --- PASS: TestIsValidUploadKey/traversal (0.00s)1828 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1829 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1830 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1831 --- PASS: TestIsValidUploadKey/index.html (0.00s)1832 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1833 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1834 --- PASS: TestIsValidUploadKey/realisation (0.00s)1835 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1836 --- PASS: TestIsValidUploadKey/listing (0.00s)1837 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1838 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1839 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1840 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1841 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1842 --- PASS: TestIsValidUploadKey/build_log (0.00s)1843 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)18442026-09-10 17:36:43.762 UTC [916] ERROR: relation "goose_db_version" does not exist at character 3618452026-09-10 17:36:43.762 UTC [916] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18462026/09/10 17:36:43 OK 20241026095416_initial_model.sql (10.21ms)18472026/09/10 17:36:43 OK 20251210153512_drop_unused_gin_index.sql (1.45ms)18482026/09/10 17:36:43 OK 20251218171726_add_pins.sql (3.82ms)18492026/09/10 17:36:43 OK 20260628120000_add_object_size_and_stats.sql (4.69ms)18502026/09/10 17:36:43 OK 20260905000000_add_claims.sql (2.48ms)18512026/09/10 17:36:43 goose: successfully migrated database to version: 2026090500000018522026/09/10 17:36:43 OK 1_commit_pending_closure.sql (1.94ms)18532026/09/10 17:36:43 OK 2_object_stats_trigger.sql (889.63µs)18542026/09/10 17:36:43 goose: up to current file version: 218552026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"18562026/09/10 17:36:43 WARN claim: cannot clear write deadline error="feature not supported"1857--- PASS: TestClaim_TooManyStreams (1.39s)1858=== CONT TestClientErrorHandling/ServerNotAvailable18592026/09/10 17:36:43 INFO Aborted multipart uploads count=018602026/09/10 17:36:43 WARN Force mode enabled - objects will be deleted immediately without grace period18612026/09/10 17:36:43 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=018622026/09/10 17:36:43 INFO Vacuumed table table=pending_closures18632026/09/10 17:36:43 INFO Vacuumed table table=pending_objects18642026/09/10 17:36:43 INFO Vacuumed table table=multipart_uploads18652026/09/10 17:36:43 INFO Vacuumed table table=closures18662026/09/10 17:36:43 INFO Vacuumed table table=objects1867=== NAME TestClientIntegration1868 client_integration_test.go:277: Created store path: /build/TestClientIntegration1413125840/002/store/d4g6ni1lb3g119yramzdxnbdk917hc63-test-file.txt1869--- PASS: TestGCMetrics (1.43s)1870=== CONT TestClientErrorHandling/InvalidAuthToken18712026/09/10 17:36:43 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-config18722026/09/10 17:36:44 INFO Received uploads request method=POST path=/api/pending_closures18732026-09-10 17:36:44.021 UTC [1014] ERROR: relation "goose_db_version" does not exist at character 3618742026-09-10 17:36:44.021 UTC [1014] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18752026/09/10 17:36:44 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18762026/09/10 17:36:44 WARN claim: cannot clear write deadline error="feature not supported"18772026/09/10 17:36:44 OK 20241026095416_initial_model.sql (10.51ms)18782026/09/10 17:36:44 OK 20251210153512_drop_unused_gin_index.sql (3.48ms)18792026/09/10 17:36:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18802026/09/10 17:36:44 OK 20251218171726_add_pins.sql (4.1ms)18812026/09/10 17:36:44 WARN claim: cannot clear write deadline error="feature not supported"18822026/09/10 17:36:44 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)18832026/09/10 17:36:44 OK 20260905000000_add_claims.sql (3.56ms)18842026/09/10 17:36:44 goose: successfully migrated database to version: 2026090500000018852026/09/10 17:36:44 OK 1_commit_pending_closure.sql (2ms)18862026/09/10 17:36:44 OK 2_object_stats_trigger.sql (998.11µs)18872026/09/10 17:36:44 goose: up to current file version: 218882026/09/10 17:36:44 WARN claim: cannot clear write deadline error="feature not supported"18892026/09/10 17:36:44 INFO Received uploads request method=POST path=/api/pending_closures18902026/09/10 17:36:44 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=YmVjZTY3ZDUtYjI4Yi00MmRmLTg3YWMtOTUwMzhhNDc4MjEzLjI5ZGE2NTc2LWY5NWMtNDY0YS05ZGE2LTM4YTczMzcxYzU4NHgxNzg5MDYxODAzNDM2NjIyMDMz parts=1018912026/09/10 17:36:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18922026/09/10 17:36:44 INFO Signed narinfos id=1 count=118932026/09/10 17:36:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18942026/09/10 17:36:44 INFO Received uploads request method=POST path=/api/pending_closures18952026/09/10 17:36:44 INFO Received uploads request method=POST path=/api/pending_closures18962026/09/10 17:36:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18972026/09/10 17:36:44 INFO Signed narinfos id=2 count=118982026/09/10 17:36:44 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18992026/09/10 17:36:44 INFO Completed upload id=219002026/09/10 17:36:44 WARN claim: cannot clear write deadline error="feature not supported"1901--- PASS: TestClaim_BuildWaitComplete (1.91s)1902=== CONT TestResolveDBConnectionString/flag_wins1903=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1904=== CONT TestResolveDBConnectionString/nothing_configured1905=== CONT TestResolveDBConnectionString/missing_file_is_an_error1906=== CONT TestResolveDBConnectionString/file_when_flag_empty1907=== CONT TestCacheConfigHandler/full_config,_no_issuer1908=== CONT TestCacheConfigHandler/no_signing_keys1909=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator19102026/09/10 17:36:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1911--- PASS: TestResolveDBConnectionString (0.00s)1912 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1913 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1914 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1915 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1916 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)19172026/09/10 17:36:44 INFO Uploading d4g6ni1lb3g119yramzdxnbdk917hc63-test-file.txt (152B)1918=== CONT TestCacheConfigHandler/no_cache_url_configured1919--- PASS: TestCacheConfigHandler (0.00s)1920 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1921 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1922 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1923 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)19242026/09/10 17:36:44 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19252026/09/10 17:36:44 WARN Failed to register uploaded object key=d4g6ni1lb3g119yramzdxnbdk917hc63.ls error="server returned 404: 404 page not found\n"19262026/09/10 17:36:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19272026/09/10 17:36:44 INFO Signed narinfos id=1 count=119282026/09/10 17:36:44 INFO Uploading 1 narinfos19292026/09/10 17:36:44 WARN Failed to register uploaded object key=d4g6ni1lb3g119yramzdxnbdk917hc63.narinfo error="server returned 404: 404 page not found\n"19302026/09/10 17:36:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19312026/09/10 17:36:44 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.463799ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19322026/09/10 17:36:44 INFO Completed upload id=119332026/09/10 17:36:44 INFO Upload complete. (110ms)1934=== NAME TestClientIntegration1935 client_integration_test.go:293: Retrieved narinfo from S3:1936 StorePath: /build/TestClientIntegration1413125840/002/store/d4g6ni1lb3g119yramzdxnbdk917hc63-test-file.txt1937 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1938 Compression: zstd1939 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11940 NarSize: 1521941 References: 1942 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11943 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1944 client_integration_test.go:294: Decompressed .ls content (64 bytes):1945 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1946 client_integration_test.go:297: Testing garbage collection...19472026/09/10 17:36:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures19482026/09/10 17:36:44 INFO Garbage collection started19492026/09/10 17:36:44 INFO Aborted multipart uploads count=019502026/09/10 17:36:44 WARN Force mode enabled - objects will be deleted immediately without grace period1951=== NAME TestClientMultipleUploads1952 client_integration_test.go:339: Created store path 0: /build/TestClientMultipleUploads2129867171/001/store/w41i2q3vchmd3bzs7dg7rc44542h18g0-test-file-0.txt1953=== NAME TestClientCADerivations1954 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2904283995/001/store/c8yi26nk5xjc3nxcjksmhf70p71rbwar-ca-test1955=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1956=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1957=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1958=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1959=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1960=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1961=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1962=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1963=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1964=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1965=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token19662026/09/10 17:36:44 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]1967=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19682026/09/10 17:36:44 WARN Authentication failed token_preview=eyJhbGciOi...qlMVt0mygA token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]19692026/09/10 17:36:44 INFO OIDC auth successful provider=test scopes=[write]1970--- PASS: TestService_AuthMiddleware_OIDC (0.98s)1971 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1972 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1973 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1974 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1975=== NAME TestClientWithDependencies1976 client_integration_test.go:594: Built derivation: /build/TestClientWithDependencies1266190062/001/store/kh9g3n5lnlafk329adwx9rr7k06m4aww-test-script1977--- PASS: TestService_ReadScope_PublicByDefault (0.99s)1978=== NAME TestClientCADerivations1979 client_ca_test.go:139: Found 1 dependencies (including self)1980=== NAME TestClientMultipleUploads1981 client_integration_test.go:339: Created store path 1: /build/TestClientMultipleUploads2129867171/001/store/a8pzmllxp2x1qcq0mp98db8gi2nbba9r-test-file-1.txt1982=== NAME TestClientWithDependencies1983 client_integration_test.go:596: Found 1 dependencies (including self)1984=== NAME TestPinProtectsFromGC1985 client_integration_test.go:648: Pinned store path: /build/TestPinProtectsFromGC3134953476/001/store/9q45cdvgm4mp2lk423yax8x920m14i47-pinned-file.txt1986 client_integration_test.go:649: Unpinned store path: /build/TestPinProtectsFromGC3134953476/001/store/h313i0iyliy0lm31a1waq24sz6h2sgps-unpinned-file.txt1987=== NAME TestClientMultipleUploads1988 client_integration_test.go:339: Created store path 2: /build/TestClientMultipleUploads2129867171/001/store/cg71cwzpzgb4r1qv4zns2jymjxysrbzl-test-file-2.txt1989=== RUN TestService_RequireScope_OIDC/builder_may_write1990=== PAUSE TestService_RequireScope_OIDC/builder_may_write1991=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1992=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1993=== RUN TestService_RequireScope_OIDC/ops_may_admin1994=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1995=== RUN TestService_RequireScope_OIDC/ops_may_not_write1996=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1997=== RUN TestService_RequireScope_OIDC/reader_may_not_write1998=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1999=== RUN TestService_RequireScope_OIDC/static_token_may_admin2000=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2001=== RUN TestService_RequireScope_OIDC/static_token_may_write2002=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2003=== RUN TestService_RequireScope_OIDC/reader_may_read2004=== PAUSE TestService_RequireScope_OIDC/reader_may_read2005=== RUN TestService_RequireScope_OIDC/writer_implies_read2006=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2007=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2008=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2009=== CONT TestService_RequireScope_OIDC/builder_may_write2010=== CONT TestService_RequireScope_OIDC/static_token_may_admin2011=== CONT TestService_RequireScope_OIDC/ops_may_not_write2012=== CONT TestService_RequireScope_OIDC/reader_may_not_write2013=== CONT TestService_RequireScope_OIDC/ops_may_admin20142026/09/10 17:36:44 INFO OIDC auth successful provider=test scopes=[write]20152026/09/10 17:36:44 INFO OIDC auth successful provider=test scopes=[admin]2016=== CONT TestService_RequireScope_OIDC/writer_implies_read20172026/09/10 17:36:44 INFO OIDC auth successful provider=test scopes=[read]2018=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2019=== CONT TestService_RequireScope_OIDC/reader_may_read20202026/09/10 17:36:44 INFO OIDC auth successful provider=test scopes=[admin]2021=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2022=== CONT TestService_RequireScope_OIDC/static_token_may_write20232026/09/10 17:36:44 INFO OIDC auth successful provider=test scopes=[write]20242026/09/10 17:36:44 INFO OIDC auth successful provider=test scopes=[read]20252026/09/10 17:36:44 INFO OIDC auth successful provider=test scopes=[write]2026--- PASS: TestService_RequireScope_OIDC (1.02s)2027 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2028 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2029 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2030 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2031 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2032 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2033 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2034 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2035 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2036 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2037--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.01s)2038--- PASS: TestGCBugBareHashReferences (1.25s)20392026/09/10 17:36:44 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=385.578698ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2040--- PASS: TestService_ReadAuthMiddleware (1.01s)20412026/09/10 17:36:44 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20422026/09/10 17:36:44 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20432026/09/10 17:36:44 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20442026/09/10 17:36:44 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20452026/09/10 17:36:44 INFO Received uploads request method=POST path=/api/pending_closures20462026/09/10 17:36:44 INFO Received uploads request method=POST path=/api/pending_closures20472026/09/10 17:36:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20482026/09/10 17:36:44 INFO Uploading kh9g3n5lnlafk329adwx9rr7k06m4aww-test-script (136B)20492026/09/10 17:36:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20502026/09/10 17:36:44 INFO Uploading c8yi26nk5xjc3nxcjksmhf70p71rbwar-ca-test (144B)20512026/09/10 17:36:44 WARN Failed to register uploaded object key=log/sb07d475j2gnmmrf1nm3671lxyqsg13i-test-script.drv error="server returned 404: 404 page not found\n"20522026/09/10 17:36:44 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"20532026/09/10 17:36:44 WARN Failed to register uploaded object key=log/1c9c2k4ml2dhjhq64frvgnyx2ysd1hb5-ca-test.drv error="server returned 404: 404 page not found\n"20542026/09/10 17:36:44 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20552026/09/10 17:36:44 INFO Received uploads request method=POST path=/api/pending_closures20562026/09/10 17:36:44 WARN Failed to register uploaded object key=kh9g3n5lnlafk329adwx9rr7k06m4aww.ls error="server returned 404: 404 page not found\n"20572026/09/10 17:36:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20582026/09/10 17:36:44 INFO Signed narinfos id=1 count=120592026/09/10 17:36:44 INFO Uploading 1 narinfos20602026/09/10 17:36:44 WARN Failed to register uploaded object key=c8yi26nk5xjc3nxcjksmhf70p71rbwar.ls error="server returned 404: 404 page not found\n"20612026/09/10 17:36:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20622026/09/10 17:36:44 INFO Signed narinfos id=1 count=120632026/09/10 17:36:44 INFO Uploading 1 narinfos20642026/09/10 17:36:44 WARN Failed to register uploaded object key=kh9g3n5lnlafk329adwx9rr7k06m4aww.narinfo error="server returned 404: 404 page not found\n"20652026/09/10 17:36:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20662026/09/10 17:36:44 INFO Received uploads request method=POST path=/api/pending_closures20672026/09/10 17:36:44 WARN Failed to register uploaded object key=c8yi26nk5xjc3nxcjksmhf70p71rbwar.narinfo error="server returned 404: 404 page not found\n"20682026/09/10 17:36:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20692026/09/10 17:36:44 INFO Received uploads request method=POST path=/api/pending_closures20702026/09/10 17:36:44 INFO Completed upload id=120712026/09/10 17:36:44 INFO Upload complete. (78ms)20722026/09/10 17:36:44 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)20732026/09/10 17:36:44 INFO Uploading cg71cwzpzgb4r1qv4zns2jymjxysrbzl-test-file-2.txt (160B)20742026/09/10 17:36:44 INFO Uploading a8pzmllxp2x1qcq0mp98db8gi2nbba9r-test-file-1.txt (160B)20752026/09/10 17:36:44 INFO Uploading w41i2q3vchmd3bzs7dg7rc44542h18g0-test-file-0.txt (160B)2076=== NAME TestClientWithDependencies2077 client_integration_test.go:598: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1266190062/001/store) requires matching store prefix20782026/09/10 17:36:44 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"20792026/09/10 17:36:44 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"20802026/09/10 17:36:44 INFO Completed upload id=120812026/09/10 17:36:44 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"20822026/09/10 17:36:44 INFO Upload complete. (153ms)2083--- PASS: TestClientWithDependencies (1.25s)20842026/09/10 17:36:44 WARN Failed to register uploaded object key=cg71cwzpzgb4r1qv4zns2jymjxysrbzl.ls error="server returned 404: 404 page not found\n"20852026/09/10 17:36:44 WARN Failed to register uploaded object key=w41i2q3vchmd3bzs7dg7rc44542h18g0.ls error="server returned 404: 404 page not found\n"20862026/09/10 17:36:44 WARN Failed to register uploaded object key=a8pzmllxp2x1qcq0mp98db8gi2nbba9r.ls error="server returned 404: 404 page not found\n"20872026/09/10 17:36:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign2088=== NAME TestClientCADerivations2089 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2904283995/001/store/c8yi26nk5xjc3nxcjksmhf70p71rbwar-ca-test2090 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2091 Compression: zstd2092 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2093 NarSize: 1442094 References: 2095 Deriver: /build/TestClientCADerivations2904283995/001/store/1c9c2k4ml2dhjhq64frvgnyx2ysd1hb5-ca-test.drv2096 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2097 client_ca_test.go:185: Checking for realisation files in S3...20982026/09/10 17:36:44 INFO Signed narinfos id=1 count=120992026/09/10 17:36:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21002026/09/10 17:36:44 INFO Signed narinfos id=2 count=121012026/09/10 17:36:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign21022026/09/10 17:36:44 INFO Signed narinfos id=3 count=121032026/09/10 17:36:44 INFO Uploading 3 narinfos2104 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations21052026/09/10 17:36:44 INFO Received uploads request method=POST path=/api/pending_closures2106 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache21072026/09/10 17:36:44 WARN Failed to register uploaded object key=w41i2q3vchmd3bzs7dg7rc44542h18g0.narinfo error="server returned 404: 404 page not found\n"21082026/09/10 17:36:44 WARN Failed to register uploaded object key=a8pzmllxp2x1qcq0mp98db8gi2nbba9r.narinfo error="server returned 404: 404 page not found\n"21092026/09/10 17:36:44 WARN Failed to register uploaded object key=cg71cwzpzgb4r1qv4zns2jymjxysrbzl.narinfo error="server returned 404: 404 page not found\n"21102026/09/10 17:36:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21112026/09/10 17:36:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21122026/09/10 17:36:44 INFO Uploading 9q45cdvgm4mp2lk423yax8x920m14i47-pinned-file.txt (128B)21132026/09/10 17:36:44 INFO Completed upload id=121142026/09/10 17:36:44 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21152026/09/10 17:36:44 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"21162026/09/10 17:36:44 INFO Completed upload id=221172026/09/10 17:36:44 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete21182026/09/10 17:36:44 INFO Completed upload id=321192026/09/10 17:36:44 INFO Upload complete. (128ms)2120=== NAME TestClientMultipleUploads2121 client_integration_test.go:350: Uploaded 3 paths in 171.657725ms21222026/09/10 17:36:44 WARN Failed to register uploaded object key=9q45cdvgm4mp2lk423yax8x920m14i47.ls error="server returned 404: 404 page not found\n"21232026/09/10 17:36:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21242026/09/10 17:36:44 INFO Signed narinfos id=1 count=121252026/09/10 17:36:44 INFO Uploading 1 narinfos21262026/09/10 17:36:44 WARN Failed to register uploaded object key=9q45cdvgm4mp2lk423yax8x920m14i47.narinfo error="server returned 404: 404 page not found\n"21272026/09/10 17:36:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete2128--- PASS: TestClientMultipleUploads (1.26s)21292026/09/10 17:36:44 INFO Completed upload id=121302026/09/10 17:36:44 INFO Upload complete. (134ms)21312026/09/10 17:36:44 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21322026/09/10 17:36:44 INFO Received uploads request method=POST path=/api/pending_closures21332026/09/10 17:36:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21342026/09/10 17:36:44 INFO Uploading h313i0iyliy0lm31a1waq24sz6h2sgps-unpinned-file.txt (128B)21352026/09/10 17:36:44 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"2136=== NAME TestClientCADerivations2137 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2138 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2139 error: binary cache 's3://bucket51?endpoint=http://localhost:33255®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2904283995/001/store'2140 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 121412026/09/10 17:36:44 WARN Failed to register uploaded object key=h313i0iyliy0lm31a1waq24sz6h2sgps.ls error="server returned 404: 404 page not found\n"21422026/09/10 17:36:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21432026/09/10 17:36:44 INFO Signed narinfos id=2 count=121442026/09/10 17:36:44 INFO Uploading 1 narinfos2145--- PASS: TestClientCADerivations (1.45s)21462026/09/10 17:36:44 WARN Failed to register uploaded object key=h313i0iyliy0lm31a1waq24sz6h2sgps.narinfo error="server returned 404: 404 page not found\n"21472026/09/10 17:36:44 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21482026/09/10 17:36:44 INFO Completed upload id=221492026/09/10 17:36:44 INFO Upload complete. (105ms)21502026/09/10 17:36:44 INFO Received create pin request method=POST path=/api/pins/myapp21512026/09/10 17:36:44 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3134953476/001/store/9q45cdvgm4mp2lk423yax8x920m14i47-pinned-file.txt narinfo_key=9q45cdvgm4mp2lk423yax8x920m14i47.narinfo21522026/09/10 17:36:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures21532026/09/10 17:36:44 INFO Garbage collection started2154--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)2155 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.12s)2156 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2157 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.26s)21582026/09/10 17:36:44 INFO Aborted multipart uploads count=021592026/09/10 17:36:44 WARN Force mode enabled - objects will be deleted immediately without grace period21602026/09/10 17:36:44 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=799.451144ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21612026/09/10 17:36:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21622026/09/10 17:36:45 WARN mTLS auth: bound subjects configured but subject DN unavailable21632026/09/10 17:36:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2164--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.69s)21652026/09/10 17:36:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21662026/09/10 17:36:45 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=YmVjZTY3ZDUtYjI4Yi00MmRmLTg3YWMtOTUwMzhhNDc4MjEzLjIxM2VkNTE4LTgwZDEtNDk4My1iNGFkLTRiZGFmYmRlOTBjMXgxNzg5MDYxODA0MDI0MjIxMTQz parts=1021672026/09/10 17:36:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21682026/09/10 17:36:45 INFO Completed upload id=121692026/09/10 17:36:45 WARN claim: cannot clear write deadline error="feature not supported"21702026/09/10 17:36:45 INFO Aborted multipart uploads count=021712026/09/10 17:36:45 WARN Force mode enabled - objects will be deleted immediately without grace period21722026/09/10 17:36:45 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=021732026/09/10 17:36:45 INFO Vacuumed table table=pending_closures21742026/09/10 17:36:45 INFO Vacuumed table table=pending_objects21752026/09/10 17:36:45 INFO Vacuumed table table=multipart_uploads21762026/09/10 17:36:45 INFO Vacuumed table table=closures21772026/09/10 17:36:45 INFO Vacuumed table table=objects2178--- PASS: TestClaim_InputsTouched (2.21s)21792026/09/10 17:36:45 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21802026/09/10 17:36:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21812026/09/10 17:36:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21822026/09/10 17:36:45 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=YmVjZTY3ZDUtYjI4Yi00MmRmLTg3YWMtOTUwMzhhNDc4MjEzLmY0NWRkY2M5LTM0OTgtNDU3Mi1hYTQyLTJkODE0ZTU5NDk2MXgxNzg5MDYxODAzMzkyOTkwMTcx parts=1021832026/09/10 17:36:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21842026/09/10 17:36:45 INFO Completed upload id=121852026/09/10 17:36:45 WARN claim: cannot clear write deadline error="feature not supported"21862026/09/10 17:36:45 WARN claim: cannot clear write deadline error="feature not supported"2187--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (3.21s)2188=== NAME TestOrphanedObjectsGCStressTest2189 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2190 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2191--- PASS: TestClaim_StreamsThroughServer (2.90s)21922026/09/10 17:36:45 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.662386776s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2193--- PASS: TestClaim_HolderDisconnectKeepsClaim (3.72s)21942026/09/10 17:36:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21952026/09/10 17:36:45 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=YmVjZTY3ZDUtYjI4Yi00MmRmLTg3YWMtOTUwMzhhNDc4MjEzLjkyYzA2NjBiLTE4NDUtNDljOC1hMGM0LTRmMGQ1MzJkYjA3NngxNzg5MDYxODA0MDYxNjgxMzkx parts=1021962026/09/10 17:36:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21972026/09/10 17:36:45 INFO Signed narinfos id=1 count=121982026/09/10 17:36:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21992026/09/10 17:36:45 INFO Completed upload id=12200--- PASS: TestClaim_TwoInstances (2.92s)2201=== NAME TestOrphanedObjectsGCStressTest2202 orphaned_objects_gc_test.go:509: Stress test completed successfully:2203 orphaned_objects_gc_test.go:510: - Active objects preserved: 202204 orphaned_objects_gc_test.go:511: - Objects deleted: 2102205 orphaned_objects_gc_test.go:512: - Total GC'd: 2102206--- PASS: TestOrphanedObjectsGCStressTest (4.55s)22072026/09/10 17:36:46 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=0 objects_failed=022082026/09/10 17:36:46 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=1000 objects_failed=022092026/09/10 17:36:47 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=022102026/09/10 17:36:47 INFO Vacuumed table table=pending_closures22112026/09/10 17:36:47 INFO Vacuumed table table=pending_objects22122026/09/10 17:36:47 INFO Vacuumed table table=multipart_uploads22132026/09/10 17:36:47 INFO Vacuumed table table=closures22142026/09/10 17:36:47 INFO Vacuumed table table=objects22152026/09/10 17:36:47 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"22162026/09/10 17:36:47 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_closures22172026/09/10 17:36:47 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.643656ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22182026/09/10 17:36:47 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=399.512761ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22192026/09/10 17:36:47 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=022202026/09/10 17:36:47 INFO Vacuumed table table=pending_closures22212026/09/10 17:36:47 INFO Vacuumed table table=pending_objects22222026/09/10 17:36:47 INFO Vacuumed table table=multipart_uploads22232026/09/10 17:36:47 INFO Vacuumed table table=closures22242026/09/10 17:36:47 INFO Vacuumed table table=objects22252026/09/10 17:36:47 WARN Rate limiter enabled after throttle name=s3-test rate=522262026/09/10 17:36:47 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2227=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2228 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102229 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002230--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.61s)22312026/09/10 17:36:47 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=726.546365ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22322026/09/10 17:36:48 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02233=== NAME TestClientIntegration2234 client_integration_test.go:304: Objects in database after GC:2235 client_integration_test.go:304: Successfully deleted all objects with GC --force2236--- PASS: TestClientIntegration (5.62s)22372026/09/10 17:36:48 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.471262977s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22382026/09/10 17:36:48 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02239=== NAME TestPinProtectsFromGC2240 client_integration_test.go:711: Pin successfully protected closure from garbage collection2241--- PASS: TestPinProtectsFromGC (5.44s)2242--- PASS: TestClientErrorHandling (0.00s)2243 --- PASS: TestClientErrorHandling/InvalidStorePath (1.43s)2244 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.31s)2245 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.23s)2246PASS2247{"timestamp":"2026-09-10T17:36:50.10663111Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:45264","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1866,"threadName":"rustfs-worker","threadId":"ThreadId(357)"}22482026-09-10 17:36:50.427 UTC [128] LOG: received smart shutdown request22492026-09-10 17:36:50.433 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 122502026-09-10 17:36:50.445 UTC [133] LOG: shutting down22512026-09-10 17:36:50.445 UTC [133] LOG: checkpoint starting: shutdown immediate22522026-09-10 17:36:51.736 UTC [133] LOG: checkpoint complete: wrote 11342 buffers (69.2%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 17 recycled; write=0.233 s, sync=1.047 s, total=1.291 s; sync files=21000, longest=0.016 s, average=0.001 s; distance=282889 kB, estimate=282889 kB; lsn=0/12BA82D8, redo lsn=0/12BA82D822532026-09-10 17:36:51.840 UTC [128] LOG: database system is shut down2254Running OIDC tests...2255=== RUN TestGlobMatch2256=== PAUSE TestGlobMatch2257=== RUN TestAudienceForIssuer2258=== PAUSE TestAudienceForIssuer2259=== RUN TestValidateToken_ValidToken2260=== PAUSE TestValidateToken_ValidToken2261=== RUN TestValidateToken_WrongAudience2262=== PAUSE TestValidateToken_WrongAudience2263=== RUN TestValidateToken_Expired2264=== PAUSE TestValidateToken_Expired2265=== RUN TestValidateToken_BoundClaimsMismatch2266=== PAUSE TestValidateToken_BoundClaimsMismatch2267=== RUN TestValidateToken_BoundSubjectMismatch2268=== PAUSE TestValidateToken_BoundSubjectMismatch2269=== RUN TestValidateToken_MultipleProviders2270=== PAUSE TestValidateToken_MultipleProviders2271=== RUN TestValidateToken_NoMatchingProvider2272=== PAUSE TestValidateToken_NoMatchingProvider2273=== RUN TestValidateToken_KubernetesServiceAccount2274=== PAUSE TestValidateToken_KubernetesServiceAccount2275=== RUN TestNewValidator_KubernetesRequiresCA2276=== PAUSE TestNewValidator_KubernetesRequiresCA2277=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2278=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2279=== RUN TestScopes_LegacyProviderDefaultsToWrite2280=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2281=== RUN TestScopes_Rules2282=== PAUSE TestScopes_Rules2283=== RUN TestScopes_ConfigValidation2284=== PAUSE TestScopes_ConfigValidation2285=== CONT TestGlobMatch2286=== CONT TestValidateToken_NoMatchingProvider2287=== RUN TestGlobMatch/foo_foo2288=== PAUSE TestGlobMatch/foo_foo2289=== RUN TestGlobMatch/foo_bar2290=== PAUSE TestGlobMatch/foo_bar2291=== RUN TestGlobMatch/*_2292=== PAUSE TestGlobMatch/*_2293=== RUN TestGlobMatch/*_anything2294=== CONT TestValidateToken_Expired2295=== CONT TestScopes_LegacyProviderDefaultsToWrite2296=== PAUSE TestGlobMatch/*_anything2297=== RUN TestGlobMatch/foo*_foo2298=== CONT TestValidateToken_WrongAudience2299=== CONT TestValidateToken_ValidToken2300=== CONT TestAudienceForIssuer2301--- PASS: TestAudienceForIssuer (0.00s)2302=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2303=== CONT TestValidateToken_BoundSubjectMismatch2304=== CONT TestValidateToken_MultipleProviders2305=== CONT TestScopes_ConfigValidation2306=== CONT TestNewValidator_KubernetesRequiresCA2307=== CONT TestValidateToken_BoundClaimsMismatch2308=== CONT TestValidateToken_KubernetesServiceAccount2309=== CONT TestScopes_Rules2310=== PAUSE TestGlobMatch/foo*_foo2311=== RUN TestGlobMatch/foo*_foobar2312=== PAUSE TestGlobMatch/foo*_foobar2313=== RUN TestGlobMatch/foo*_bar2314=== PAUSE TestGlobMatch/foo*_bar2315=== RUN TestGlobMatch/*bar_bar2316=== PAUSE TestGlobMatch/*bar_bar2317=== RUN TestGlobMatch/*bar_foobar2318=== PAUSE TestGlobMatch/*bar_foobar2319=== RUN TestGlobMatch/*bar_foo2320=== PAUSE TestGlobMatch/*bar_foo2321=== RUN TestGlobMatch/foo*bar_foobar2322=== PAUSE TestGlobMatch/foo*bar_foobar2323=== RUN TestGlobMatch/foo*bar_foo123bar2324=== PAUSE TestGlobMatch/foo*bar_foo123bar2325=== RUN TestGlobMatch/foo*bar_foobarbaz2326=== PAUSE TestGlobMatch/foo*bar_foobarbaz2327=== RUN TestGlobMatch/*/*_foo/bar2328=== PAUSE TestGlobMatch/*/*_foo/bar2329=== RUN TestGlobMatch/*/*_foo2330=== PAUSE TestGlobMatch/*/*_foo2331=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2332=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2333=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02334=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02335=== RUN TestGlobMatch/refs/*/main_refs/heads/main2336=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2337=== RUN TestGlobMatch/fo?_foo2338=== PAUSE TestGlobMatch/fo?_foo2339=== RUN TestGlobMatch/fo?_fo2340=== PAUSE TestGlobMatch/fo?_fo2341=== RUN TestGlobMatch/fo?_fooo2342=== PAUSE TestGlobMatch/fo?_fooo2343=== RUN TestGlobMatch/?oo_foo2344=== PAUSE TestGlobMatch/?oo_foo2345=== RUN TestGlobMatch/?oo_boo2346--- PASS: TestScopes_ConfigValidation (0.00s)2347=== PAUSE TestGlobMatch/?oo_boo2348=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2349=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2350=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2351=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2352=== CONT TestGlobMatch/foo_foo2353=== CONT TestGlobMatch/refs/*/main_refs/heads/main2354=== CONT TestGlobMatch/foo*bar_foobarbaz2355=== CONT TestGlobMatch/*/*_foo/bar2356=== CONT TestGlobMatch/foo*_foobar2357=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2358=== CONT TestGlobMatch/*bar_foo2359=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02360=== CONT TestGlobMatch/*bar_foobar2361=== CONT TestGlobMatch/foo*_foo2362=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2363=== CONT TestGlobMatch/fo?_fooo2364=== CONT TestGlobMatch/foo*_bar2365=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2366=== CONT TestGlobMatch/*_anything2367=== CONT TestGlobMatch/foo*bar_foo123bar2368=== CONT TestGlobMatch/foo*bar_foobar2369=== CONT TestGlobMatch/?oo_boo2370=== CONT TestGlobMatch/*_2371=== CONT TestGlobMatch/fo?_foo2372=== CONT TestGlobMatch/?oo_foo2373=== CONT TestGlobMatch/*/*_foo2374=== CONT TestGlobMatch/fo?_fo2375=== CONT TestGlobMatch/foo_bar2376=== CONT TestGlobMatch/*bar_bar2377--- PASS: TestGlobMatch (0.01s)2378 --- PASS: TestGlobMatch/foo_foo (0.00s)2379 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2380 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2381 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2382 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2383 --- PASS: TestGlobMatch/*bar_foo (0.00s)2384 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2385 --- PASS: TestGlobMatch/foo*_bar (0.00s)2386 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2387 --- PASS: TestGlobMatch/*_anything (0.00s)2388 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2389 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2390 --- PASS: TestGlobMatch/?oo_boo (0.00s)2391 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2392 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2393 --- PASS: TestGlobMatch/*_ (0.00s)2394 --- PASS: TestGlobMatch/fo?_foo (0.00s)2395 --- PASS: TestGlobMatch/?oo_foo (0.00s)2396 --- PASS: TestGlobMatch/*/*_foo (0.00s)2397 --- PASS: TestGlobMatch/fo?_fo (0.00s)2398 --- PASS: TestGlobMatch/foo_bar (0.00s)2399 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2400 --- PASS: TestGlobMatch/foo*_foo (0.00s)2401 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2402 --- PASS: TestGlobMatch/*bar_bar (0.00s)24032026/09/10 17:36:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43179/oidc24042026/09/10 17:36:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36685/oidc24052026/09/10 17:36:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35459/oidc24062026/09/10 17:36:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42977/oidc24072026/09/10 17:36:53 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45231/oidc24082026/09/10 17:36:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40715/oidc24092026/09/10 17:36:53 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42223/oidc24102026/09/10 17:36:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33803/oidc24112026/09/10 17:36:53 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324122026/09/10 17:36:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40067/oidc24132026/09/10 17:36:53 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:33345/oidc2414--- PASS: TestValidateToken_Expired (0.01s)2415--- PASS: TestValidateToken_WrongAudience (0.01s)2416--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2417--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2418--- PASS: TestValidateToken_ValidToken (0.01s)2419--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2420--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2421--- PASS: TestValidateToken_MultipleProviders (0.01s)24222026/09/10 17:36:53 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:342492423--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)24242026/09/10 17:36:53 http: TLS handshake error from 127.0.0.1:57116: remote error: tls: bad certificate2425--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2426--- PASS: TestScopes_Rules (0.02s)2427--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)2428PASS2429Running hook tests...2430=== RUN TestSendPathsEmpty2431=== PAUSE TestSendPathsEmpty2432=== RUN TestQueueEnqueueAndFetch2433=== PAUSE TestQueueEnqueueAndFetch2434=== RUN TestQueueDeduplication2435=== PAUSE TestQueueDeduplication2436=== RUN TestQueueRemove2437=== PAUSE TestQueueRemove2438=== RUN TestQueueFetchBatchLimit2439=== PAUSE TestQueueFetchBatchLimit2440=== RUN TestQueueRetryMovesToBack2441=== PAUSE TestQueueRetryMovesToBack2442=== RUN TestQueueFetchRemoveLifecycle2443=== PAUSE TestQueueFetchRemoveLifecycle2444=== RUN TestQueueConcurrentWriters2445=== PAUSE TestQueueConcurrentWriters2446=== RUN TestQueueRemoveLargeClosure2447=== PAUSE TestQueueRemoveLargeClosure2448=== RUN TestServerClientIntegration2449=== PAUSE TestServerClientIntegration2450=== RUN TestServerQueueError2451=== PAUSE TestServerQueueError2452=== RUN TestGetListenerSocketActivation2453 server_test.go:213: === RUN TestGetListenerSocketActivation2454 --- PASS: TestGetListenerSocketActivation (0.00s)2455 PASS2456 2457--- PASS: TestGetListenerSocketActivation (0.01s)2458=== RUN TestServerWait2459=== PAUSE TestServerWait2460=== RUN TestDrainIsolatesPoisonPath2461=== PAUSE TestDrainIsolatesPoisonPath2462=== RUN TestRunNotBlockedByPoisonHead2463=== PAUSE TestRunNotBlockedByPoisonHead2464=== RUN TestDrainGivesUpWhenServerDown2465=== PAUSE TestDrainGivesUpWhenServerDown2466=== RUN TestFailedPathPrunedByLaterClosure2467=== PAUSE TestFailedPathPrunedByLaterClosure2468=== RUN TestWorkerUploadsAndRemoves2469=== PAUSE TestWorkerUploadsAndRemoves2470=== RUN TestWorkerSkipsGCdPaths2471=== PAUSE TestWorkerSkipsGCdPaths2472=== RUN TestWorkerPrunesClosureDeps2473=== PAUSE TestWorkerPrunesClosureDeps2474=== RUN TestDrainTimeout2475=== PAUSE TestDrainTimeout2476=== CONT TestSendPathsEmpty2477=== CONT TestDrainIsolatesPoisonPath2478=== CONT TestQueueFetchRemoveLifecycle2479=== CONT TestWorkerPrunesClosureDeps2480--- PASS: TestSendPathsEmpty (0.00s)2481=== CONT TestQueueRetryMovesToBack2482=== CONT TestQueueFetchBatchLimit2483=== CONT TestQueueRemove2484=== CONT TestQueueDeduplication2485=== CONT TestQueueEnqueueAndFetch2486=== CONT TestServerClientIntegration2487=== CONT TestServerWait2488=== CONT TestServerQueueError2489=== CONT TestQueueRemoveLargeClosure2490=== CONT TestQueueConcurrentWriters2491=== CONT TestWorkerUploadsAndRemoves2492=== CONT TestWorkerSkipsGCdPaths2493=== CONT TestDrainTimeout24942026/09/10 17:36:53 ERROR Hook request failed error="permission denied" wait=false count=124952026/09/10 17:36:53 ERROR Hook request failed error="409 stale claim" wait=true count=12496=== CONT TestDrainGivesUpWhenServerDown2497=== CONT TestFailedPathPrunedByLaterClosure2498=== CONT TestRunNotBlockedByPoisonHead2499--- PASS: TestServerWait (0.00s)2500--- PASS: TestServerClientIntegration (0.00s)2501--- PASS: TestServerQueueError (0.00s)25022026/09/10 17:36:53 INFO Uploading batch count=225032026/09/10 17:36:53 INFO Uploading batch count=425042026/09/10 17:36:53 ERROR Upload failed error="upload failed" count=425052026/09/10 17:36:53 INFO Upload queue status pending=225062026/09/10 17:36:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2110665512/002/bbb25072026/09/10 17:36:53 INFO Upload queue status pending=225082026/09/10 17:36:53 INFO Uploading batch count=125092026/09/10 17:36:53 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1422137171/002/nonexistent25102026/09/10 17:36:53 INFO Uploading batch count=225112026/09/10 17:36:53 ERROR Upload failed error="upload failed" count=12512--- PASS: TestQueueFetchBatchLimit (0.02s)25132026/09/10 17:36:53 INFO Upload queue status pending=225142026/09/10 17:36:53 INFO Uploading batch count=125152026/09/10 17:36:53 INFO Uploading batch count=125162026/09/10 17:36:53 INFO Uploading batch count=12517--- PASS: TestQueueRetryMovesToBack (0.02s)25182026/09/10 17:36:53 INFO Uploading batch count=125192026/09/10 17:36:53 INFO Upload queue status pending=325202026/09/10 17:36:53 INFO Uploading batch count=125212026/09/10 17:36:53 ERROR Upload failed error="upload failed" count=12522--- PASS: TestQueueRemove (0.02s)25232026/09/10 17:36:53 INFO Uploading batch count=125242026/09/10 17:36:53 ERROR Upload failed error="upload failed" count=125252026/09/10 17:36:53 INFO Uploading batch count=225262026/09/10 17:36:53 ERROR Upload failed error="upload failed" count=225272026/09/10 17:36:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2852219473/002/a2528--- PASS: TestQueueDeduplication (0.02s)2529--- PASS: TestQueueEnqueueAndFetch (0.02s)25302026/09/10 17:36:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2852219473/002/b25312026/09/10 17:36:53 INFO Uploading batch count=125322026/09/10 17:36:53 ERROR Upload failed error="upload failed" count=125332026/09/10 17:36:53 INFO Uploading batch count=225342026/09/10 17:36:53 ERROR Upload failed error="upload failed" count=225352026/09/10 17:36:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2852219473/002/c2536--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2537--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25382026/09/10 17:36:53 INFO Uploading batch count=125392026/09/10 17:36:53 ERROR Upload failed error="upload failed" count=125402026/09/10 17:36:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2852219473/002/d25412026/09/10 17:36:53 ERROR Drain finished with paths left in queue remaining=125422026/09/10 17:36:53 INFO Uploading batch count=225432026/09/10 17:36:53 ERROR Upload failed error="upload failed" count=225442026/09/10 17:36:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2852219473/002/e25452026/09/10 17:36:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2852219473/002/f25462026/09/10 17:36:53 ERROR Drain finished with paths left in queue remaining=102547--- PASS: TestDrainIsolatesPoisonPath (0.02s)2548--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2549--- PASS: TestWorkerUploadsAndRemoves (0.03s)2550--- PASS: TestWorkerSkipsGCdPaths (0.03s)2551--- PASS: TestWorkerPrunesClosureDeps (0.04s)2552--- PASS: TestQueueRemoveLargeClosure (0.18s)25532026/09/10 17:36:53 ERROR Upload failed error="context deadline exceeded" count=225542026/09/10 17:36:53 ERROR Drain finished with paths left in queue remaining=42555--- PASS: TestDrainTimeout (0.21s)2556--- PASS: TestQueueConcurrentWriters (0.22s)25572026/09/10 17:36:54 INFO Uploading batch count=125582026/09/10 17:36:54 INFO Uploading batch count=125592026/09/10 17:36:54 INFO Uploading batch count=125602026/09/10 17:36:54 ERROR Upload failed error="upload failed" count=125612026/09/10 17:36:54 INFO Uploading batch count=125622026/09/10 17:36:54 ERROR Upload failed error="upload failed" count=125632026/09/10 17:36:54 INFO Uploading batch count=125642026/09/10 17:36:54 ERROR Upload failed error="upload failed" count=125652026/09/10 17:36:54 INFO Uploading batch count=125662026/09/10 17:36:54 ERROR Upload failed error="upload failed" count=125672026/09/10 17:36:54 ERROR Drain finished with paths left in queue remaining=12568--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2569PASS