search

cockroachdb / cockroach

CockroachDB — the cloud native, distributed SQL database designed for high availability, effortless scale, and control over data placement.
https://www.cockroachlabs.com
Other
30.16k stars 3.82k forks source link

ccl/utilccl: TestRefreshLicenseEnforcerOnLicenseChange failed #135809

Open cockroach-teamcity opened 2 days ago

cockroach-teamcity commented 2 days ago

ccl/utilccl.TestRefreshLicenseEnforcerOnLicenseChange failed with artifacts on release-23.1.29-rc @ cb0646dc26328963ca2c89d7a8d105d166836d6d:

I241120 10:50:09.627678 1750 1@util/log/event_log.go:27  [T1,n1,job=MIGRATION id=1022457969303584769,upgrade=22.2-98,intExec=set-SQLStatsTables-TTL] 160 ={"Timestamp":1732099809624615479,"EventType":"set_zone_config","Statement":"ALTER TABLE \"\".system.transaction_activity CONFIGURE ZONE USING \"gc.ttlseconds\" = $1","Tag":"CONFIGURE ZONE","User":"root","DescriptorID":61,"ApplicationName":"$ internal-set-SQLStatsTables-TTL","PlaceholderValues":["3600"],"Target":"TABLE system.public.transaction_activity","Options":["\"gc.ttlseconds\" = 3600"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:14400 > num_replicas:5 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.628609 1598 jobs/registry.go:1623  [T1,n1] 161  MIGRATION job 1022457969303584769: stepping through state succeeded
I241120 10:50:09.645229 59 jobs/wait.go:140  [T1,n1] 162  waited for 1 [1022457969303584769] queued jobs to complete 55.832986ms
I241120 10:50:09.645405 59 upgrade/upgrademanager/manager.go:278  [T1,n1] 163  running permanent upgrade for version 22.2-102
I241120 10:50:09.655405 59 upgrade/upgrademanager/manager.go:737  [T1,n1] 164  running Upgrade to 22.2-102: "create sql activity updater job"
I241120 10:50:09.655470 1796 jobs/adopt.go:256  [T1,n1] 165  job 1022457969526145025: resuming execution
I241120 10:50:09.668907 1790 jobs/registry.go:1623  [T1,n1] 166  MIGRATION job 1022457969526145025: stepping through state running
I241120 10:50:09.683036 1790 jobs/registry.go:1623  [T1,n1] 167  MIGRATION job 1022457969526145025: stepping through state succeeded
I241120 10:50:09.700187 59 jobs/wait.go:140  [T1,n1] 168  waited for 1 [1022457969526145025] queued jobs to complete 44.73033ms
I241120 10:50:09.700235 59 server/server_sql.go:1633  [T1,n1] 169  done ensuring all necessary startup migrations have run
I241120 10:50:09.700506 1853 jobs/job_scheduler.go:402  [T1,n1] 170  waiting 4m0s before scheduled jobs daemon start
I241120 10:50:09.700557 59 server/license/enforcer.go:233  [T1,n1] 171  trial license expiry initialized to 1970-01-01 00:00:00 +0000 UTC
I241120 10:50:09.701822 59 server/license/enforcer.go:630  [T1,n1] 172  cluster init is not within the bounds of the enforcer start time: 2024-11-20 10:50:09.01875 +0000 UTC
I241120 10:50:09.701868 59 server/license/enforcer.go:264  [T1,n1] 173  generated new cluster init grace period end time: 2024-09-21 12:28:36 +0000 UTC
I241120 10:50:09.702509 59 server/license/enforcer.go:447  [T1,n1] 174  enforcer license updated: type is none, grace period ends at "2024-09-21 12:28:36 +0000 UTC", telemetry required: false
I241120 10:50:09.702555 59 server/license/enforcer.go:447  [T1,n1] 175  enforcer license updated: type is none, grace period ends at "2024-09-21 12:28:36 +0000 UTC", telemetry required: false
I241120 10:50:09.702856 1728 kv/kvclient/rangefeed/rangefeedcache/watcher.go:330  [T1,n1] 176  tenant-settings-watcher: established range feed cache
I241120 10:50:09.703923 1898 kv/kvclient/rangefeed/rangefeedcache/watcher.go:330  [T1,n1] 177  tenant-capability-watcher: established range feed cache
I241120 10:50:09.704966 1898 multitenant/tenantcapabilities/tenantcapabilitieswatcher/watcher.go:144  [T1,n1] 178  received results of a full table scan for tenant capabilities
I241120 10:50:09.705552 1726 server/auto_upgrade.go:73  [T1,n1] 179  no need to upgrade, cluster already at the newest version
I241120 10:50:09.705619 1855 sql/syntheticprivilegecache/cache.go:199  [T1,n1] 180  warmed privileges for virtual tables in 5.017185ms
I241120 10:50:09.730043 225 3@pebble/event.go:717  [n1,s1,pebble] 181  [JOB 7] WAL created 000006
I241120 10:50:09.745619 1872 1@util/log/event_log.go:27  [intExec=set-zone] 182 ={"Timestamp":1732099809744111432,"EventType":"set_zone_config","Statement":"ALTER RANGE default CONFIGURE ZONE USING num_replicas = 1","Tag":"CONFIGURE ZONE","User":"root","ApplicationName":"$ internal-set-zone","Target":"RANGE default","Options":["num_replicas = 1"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:14400 > num_replicas:1 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.749722 1987 1@util/log/event_log.go:27  [intExec=set-zone] 183 ={"Timestamp":1732099809747605384,"EventType":"set_zone_config","Statement":"ALTER DATABASE system CONFIGURE ZONE USING num_replicas = 1","Tag":"CONFIGURE ZONE","User":"root","DescriptorID":1,"ApplicationName":"$ internal-set-zone","Target":"DATABASE system","Options":["num_replicas = 1"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:14400 > num_replicas:5 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.753328 2019 1@util/log/event_log.go:27  [intExec=set-zone] 184 ={"Timestamp":1732099809749965677,"EventType":"set_zone_config","Statement":"ALTER RANGE meta CONFIGURE ZONE USING num_replicas = 1","Tag":"CONFIGURE ZONE","User":"root","DescriptorID":16,"ApplicationName":"$ internal-set-zone","Target":"RANGE meta","Options":["num_replicas = 1"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:3600 > num_replicas:5 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.757133 1998 1@util/log/event_log.go:27  [intExec=set-zone] 185 ={"Timestamp":1732099809755206730,"EventType":"set_zone_config","Statement":"ALTER RANGE system CONFIGURE ZONE USING num_replicas = 1","Tag":"CONFIGURE ZONE","User":"root","DescriptorID":17,"ApplicationName":"$ internal-set-zone","Target":"RANGE system","Options":["num_replicas = 1"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:14400 > num_replicas:5 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.761045 2037 1@util/log/event_log.go:27  [intExec=set-zone] 186 ={"Timestamp":1732099809757356886,"EventType":"set_zone_config","Statement":"ALTER RANGE liveness CONFIGURE ZONE USING num_replicas = 1","Tag":"CONFIGURE ZONE","User":"root","DescriptorID":22,"ApplicationName":"$ internal-set-zone","Target":"RANGE liveness","Options":["num_replicas = 1"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:600 > num_replicas:5 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.764985 2048 1@util/log/event_log.go:27  [intExec=set-zone] 187 ={"Timestamp":1732099809761273314,"EventType":"set_zone_config","Statement":"ALTER TABLE system.public.replication_constraint_stats CONFIGURE ZONE USING num_replicas = 1","Tag":"CONFIGURE ZONE","User":"root","DescriptorID":25,"ApplicationName":"$ internal-set-zone","Target":"TABLE system.public.replication_constraint_stats","Options":["num_replicas = 1"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:600 > num_replicas:1 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.767236 2031 1@util/log/event_log.go:27  [intExec=set-zone] 188 ={"Timestamp":1732099809765251670,"EventType":"set_zone_config","Statement":"ALTER TABLE system.public.replication_stats CONFIGURE ZONE USING num_replicas = 1","Tag":"CONFIGURE ZONE","User":"root","DescriptorID":27,"ApplicationName":"$ internal-set-zone","Target":"TABLE system.public.replication_stats","Options":["num_replicas = 1"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:600 > num_replicas:1 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.779556 2082 1@util/log/event_log.go:27  [intExec=set-zone] 189 ={"Timestamp":1732099809775854007,"EventType":"set_zone_config","Statement":"ALTER TABLE system.public.statement_statistics CONFIGURE ZONE USING num_replicas = 1","Tag":"CONFIGURE ZONE","User":"root","DescriptorID":42,"ApplicationName":"$ internal-set-zone","Target":"TABLE system.public.statement_statistics","Options":["num_replicas = 1"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:3600 > num_replicas:1 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.783531 2060 1@util/log/event_log.go:27  [intExec=set-zone] 190 ={"Timestamp":1732099809779851803,"EventType":"set_zone_config","Statement":"ALTER TABLE system.public.transaction_statistics CONFIGURE ZONE USING num_replicas = 1","Tag":"CONFIGURE ZONE","User":"root","DescriptorID":43,"ApplicationName":"$ internal-set-zone","Target":"TABLE system.public.transaction_statistics","Options":["num_replicas = 1"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:3600 > num_replicas:1 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.787038 2116 1@util/log/event_log.go:27  [intExec=set-zone] 191 ={"Timestamp":1732099809783764796,"EventType":"set_zone_config","Statement":"ALTER TABLE system.public.tenant_usage CONFIGURE ZONE USING num_replicas = 1","Tag":"CONFIGURE ZONE","User":"root","DescriptorID":45,"ApplicationName":"$ internal-set-zone","Target":"TABLE system.public.tenant_usage","Options":["num_replicas = 1"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:7200 > num_replicas:1 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.789838 2088 1@util/log/event_log.go:27  [intExec=set-zone] 192 ={"Timestamp":1732099809787334300,"EventType":"set_zone_config","Statement":"ALTER TABLE system.public.span_stats_tenant_boundaries CONFIGURE ZONE USING num_replicas = 1","Tag":"CONFIGURE ZONE","User":"root","DescriptorID":57,"ApplicationName":"$ internal-set-zone","Target":"TABLE system.public.span_stats_tenant_boundaries","Options":["num_replicas = 1"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:3600 > num_replicas:1 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.792836 1912 1@util/log/event_log.go:27  [intExec=set-zone] 193 ={"Timestamp":1732099809790125571,"EventType":"set_zone_config","Statement":"ALTER TABLE system.public.statement_activity CONFIGURE ZONE USING num_replicas = 1","Tag":"CONFIGURE ZONE","User":"root","DescriptorID":60,"ApplicationName":"$ internal-set-zone","Target":"TABLE system.public.statement_activity","Options":["num_replicas = 1"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:3600 > num_replicas:1 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.795323 2138 1@util/log/event_log.go:27  [intExec=set-zone] 194 ={"Timestamp":1732099809793100547,"EventType":"set_zone_config","Statement":"ALTER TABLE system.public.transaction_activity CONFIGURE ZONE USING num_replicas = 1","Tag":"CONFIGURE ZONE","User":"root","DescriptorID":61,"ApplicationName":"$ internal-set-zone","Target":"TABLE system.public.transaction_activity","Options":["num_replicas = 1"],"ResolvedOldConfig":"range_min_bytes:134217728 range_max_bytes:536870912 gc:<ttl_seconds:3600 > num_replicas:1 inherited_constraints:false null_voter_constraints_is_empty:true inherited_lease_preferences:false "}
I241120 10:50:09.795855 59 1@server/initial_sql.go:42  [-] 195  Replication was disabled for this cluster.
I241120 10:50:09.795855 59 1@server/initial_sql.go:42  [-] 195 +When/if adding nodes in the future, update zone configurations to increase the replication factor.
I241120 10:50:09.795895 59 1@server/server_sql.go:1781  [T1,n1] 196  serving sql connections
I241120 10:50:09.803080 2150 4@util/log/event_log.go:27  [T1,n1,client=127.0.0.1:35560,hostssl,user=root] 197 ={"Timestamp":1732099809803077265,"EventType":"client_authentication_ok","InstanceID":1,"Network":"tcp","RemoteAddress":"127.0.0.1:35560","SessionID":"1809a79996d1f3280000000000000001","Transport":"hostssl","User":"root","SystemIdentity":"root","Method":"cert-password"}
I241120 10:50:09.805109 2150 util/log/event_log.go:27  [T1,n1,client=127.0.0.1:35560,hostssl,user=root] 198 ={"Timestamp":1732099809803331839,"EventType":"set_cluster_setting","Statement":"SET CLUSTER SETTING \"cluster.organization\" = 'CRDB Unit Test'","Tag":"SET CLUSTER SETTING","User":"root","SettingName":"cluster.organization","Value":"'CRDB Unit Test'"}
--- FAIL: TestRefreshLicenseEnforcerOnLicenseChange (1.04s)
=== RUN   TestRefreshLicenseEnforcerOnLicenseChange/test_2
    license_check_test.go:274: 
            Error Trace:    github.com/cockroachdb/cockroach/pkg/ccl/utilccl/license_check_test.go:274
            Error:          Not equal: 
                            expected: 0
                            actual  : 946728000
            Test:           TestRefreshLicenseEnforcerOnLicenseChange/test_2
I241120 10:50:09.818962 2127 server/license/enforcer.go:501  [-] 206  trial license expiry was reset
    --- FAIL: TestRefreshLicenseEnforcerOnLicenseChange/test_2 (0.00s)

Parameters:

See also: How To Investigate a Go Test Failure (internal)

Same failure on other branches

- #133813 ccl/utilccl: TestRefreshLicenseEnforcerOnLicenseChange failed [C-test-failure O-robot branch-release-23.1 release-blocker]

/cc @cockroachdb/server

This test on roachdash | Improve this report!

Jira issue: CRDB-44728