Skip to content

Push on master

Push on master #12

GitHub Actions / Postgres (Results) failed Sep 30, 2024 in 0s

12887 tests run, 12842 passed, 36 skipped, 9 failed, 3 retried.

Annotations

Check failure on line 1 in com/mattermost/mattermost/server/v8/channels/api4

See this annotation in the file changed.

@github-actions github-actions / Postgres (Results)

com/mattermost/mattermost/server/v8/channels/api4.TestSyncLdap/SystemAdminClient#01

Failed
Raw output
=== RUN   TestSyncLdap/SystemAdminClient#01
{"timestamp":"2024-09-30 07:35:40.282 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/ldap/sync","request_id":"f8g1i7hu87ykijrx9ydcdahhph","user_id":"yzq1wj7a5ir57x6tads7oexx6a","status_code":"200"}
==================
WARNING: DATA RACE
Read at 0x00c004c08cc0 by goroutine 325518:
  reflect.maplen()
      /usr/local/go/src/runtime/map.go:1406 +0x0
  reflect.Value.lenNonSlice()
      /usr/local/go/src/reflect/value.go:1785 +0x1e9
  reflect.Value.Len()
      /usr/local/go/src/reflect/value.go:1774 +0x137
  internal/fmtsort.Sort()
      /usr/local/go/src/internal/fmtsort/sort.go:58 +0x121
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:816 +0x1144
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:853 +0x1d3e
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:853 +0x1d3e
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:921 +0x132a
  fmt.(*pp).printArg()
      /usr/local/go/src/fmt/print.go:759 +0xb84
  fmt.(*pp).doPrintf()
      /usr/local/go/src/fmt/print.go:1174 +0x10ce
  fmt.Sprintf()
      /usr/local/go/src/fmt/print.go:239 +0x5c
  github.com/stretchr/testify/mock.Arguments.Diff()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:939 +0x1b2
  github.com/stretchr/testify/mock.(*Mock).findExpectedCall()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:368 +0x147
  github.com/stretchr/testify/mock.(*Mock).MethodCalled()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:476 +0xac
  github.com/stretchr/testify/mock.(*Mock).Called()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:466 +0x195
  github.com/mattermost/mattermost/server/v8/einterfaces/mocks.(*LdapInterface).StartSynchronizeJob()
      /mattermost/server/einterfaces/mocks/LdapInterface.go:406 +0x1b0
  github.com/mattermost/mattermost/server/v8/channels/app.(*App).SyncLdap.func1()
      /mattermost/server/channels/app/ldap.go:33 +0x1d8
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).Go.func1()
      /mattermost/server/channels/app/platform/goroutines.go:14 +0x37

Previous write at 0x00c004c08cc0 by goroutine 325456:
  runtime.mapclear()
      /usr/local/go/src/runtime/map.go:989 +0x0
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).ReturnSessionToPool()
      /mattermost/server/channels/app/platform/session.go:25 +0xcf
  github.com/mattermost/mattermost/server/v8/channels/app.(*App).ReturnSessionToPool()
      /mattermost/server/channels/app/session.go:227 +0x26
  github.com/mattermost/mattermost/server/v8/channels/web.Handler.ServeHTTP.deferwrap1()
      /mattermost/server/channels/web/handlers.go:295 +0x55
  runtime.deferreturn()
      /usr/local/go/src/runtime/panic.go:602 +0x5d
  github.com/mattermost/mattermost/server/v8/channels/web.(*Handler).ServeHTTP()
      <autogenerated>:1 +0xe7
  github.com/klauspost/compress/gzhttp.NewWrapper.func1.1()
      /go/pkg/mod/github.com/klauspost/[email protected]/gzhttp/compress.go:495 +0x7c6
  net/http.HandlerFunc.ServeHTTP()
      /usr/local/go/src/net/http/server.go:2171 +0x47
  github.com/gorilla/mux.(*Router).ServeHTTP()
      /go/pkg/mod/github.com/gorilla/[email protected]/mux.go:212 +0x371
  net/http.serverHandler.ServeHTTP()
      /usr/local/go/src/net/http/server.go:3142 +0x2a1
  net/http.(*conn).serve()
      /usr/local/go/src/net/http/server.go:2044 +0x13c4
  net/http.(*Server).Serve.gowrap3()
      /usr/local/go/src/net/http/server.go:3290 +0x4f

Goroutine 325518 (running) created at:
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).Go()
      /mattermost/server/channels/app/platform/goroutines.go:13 +0xec
  github.com/mattermost/mattermost/server/v8/channels/app.(*Server).Go()
      /mattermost/server/channels/app/server.go:806 +0x148
  github.com/mattermost/mattermost/server/v8/channels/app.(*App).SyncLdap()
      /mattermost/server/channels/app/ldap.go:21 +0x5d
  github.com/mattermost/mattermost/server/v8/channels/api4.syncLdap()
      /mattermost/server/channels/api4/ldap.go:69 +0x9de
  github.com/mattermost/mattermost/server/v8/channels/web.Handler.ServeHTTP()
      /mattermost/server/channels/web/handlers.go:387 +0x6645
  github.com/mattermost/mattermost/server/v8/channels/web.(*Handler).ServeHTTP()
      <autogenerated>:1 +0xe7
  github.com/klauspost/compress/gzhttp.NewWrapper.func1.1()
      /go/pkg/mod/github.com/klauspost/[email protected]/gzhttp/compress.go:495 +0x7c6
  net/http.HandlerFunc.ServeHTTP()
      /usr/local/go/src/net/http/server.go:2171 +0x47
  github.com/gorilla/mux.(*Router).ServeHTTP()
      /go/pkg/mod/github.com/gorilla/[email protected]/mux.go:212 +0x371
  net/http.serverHandler.ServeHTTP()
      /usr/local/go/src/net/http/server.go:3142 +0x2a1
  net/http.(*conn).serve()
      /usr/local/go/src/net/http/server.go:2044 +0x13c4
  net/http.(*Server).Serve.gowrap3()
      /usr/local/go/src/net/http/server.go:3290 +0x4f

Goroutine 325456 (running) created at:
  net/http.(*Server).Serve()
      /usr/local/go/src/net/http/server.go:3290 +0x8ec
  github.com/mattermost/mattermost/server/v8/channels/app.(*Server).Start.func2()
      /mattermost/server/channels/app/server.go:1070 +0x224
==================
{"timestamp":"2024-09-30 07:35:40.284 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/ldap/sync","request_id":"ro9b1ewwtfyepq95n3oz6bpw3e","user_id":"yzq1wj7a5ir57x6tads7oexx6a","status_code":"200"}
    testing.go:1398: race detected during execution of test
--- FAIL: TestSyncLdap/SystemAdminClient#01 (0.01s)

Check failure on line 1 in com/mattermost/mattermost/server/v8/channels/api4

See this annotation in the file changed.

@github-actions github-actions / Postgres (Results)

com/mattermost/mattermost/server/v8/channels/api4.TestSyncLdap

Failed
Raw output
=== RUN   TestSyncLdap
{"timestamp":"2024-09-30 07:35:38.964 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 07:35:38.964 Z","level":"info","msg":"Successfully connected to cache backend","caller":"platform/service.go:191","backend":"redis","result":"PONG"}
{"timestamp":"2024-09-30 07:35:38.964 Z","level":"info","msg":"Server is initializing...","caller":"platform/service.go:194","go_version":"go1.22.6"}
{"timestamp":"2024-09-30 07:35:38.967 Z","level":"info","msg":"Starting websocket hubs","caller":"platform/web_hub.go:106","number_of_hubs":4}
{"timestamp":"2024-09-30 07:35:38.967 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":0}
{"timestamp":"2024-09-30 07:35:38.967 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":1}
{"timestamp":"2024-09-30 07:35:38.967 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":3}
{"timestamp":"2024-09-30 07:35:38.967 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":2}
{"timestamp":"2024-09-30 07:35:38.968 Z","level":"info","msg":"Loaded system translations","caller":"i18n/i18n.go:175","for locale":"en","from locale":"/mattermost/server/i18n/en.json"}
{"timestamp":"2024-09-30 07:35:38.975 Z","level":"info","msg":"Ensuring the telemetry ID..","caller":"telemetry/telemetry.go:147"}
{"timestamp":"2024-09-30 07:35:38.976 Z","level":"info","msg":"telemetry ID is set","caller":"telemetry/telemetry.go:157","id":"5qrd8x4offy1idtfmw8wc4p4kc"}
{"timestamp":"2024-09-30 07:35:38.995 Z","level":"error","msg":"SiteURL must be set. Some features will operate incorrectly if the SiteURL is not set. See documentation for details: https://mattermost.com/pl/configure-site-url","caller":"app/server.go:390"}
{"timestamp":"2024-09-30 07:35:38.995 Z","level":"info","msg":"Current version is 10.1.0 (///)","caller":"app/server.go:404","current_version":"10.1.0","build_number":"","build_date":"","build_hash":"","build_hash_enterprise":"","service_environment":"dev"}
{"timestamp":"2024-09-30 07:35:38.995 Z","level":"info","msg":"Team Edition Build","caller":"app/server.go:420","enterprise_build":false}
{"timestamp":"2024-09-30 07:35:38.995 Z","level":"info","msg":"Printing current working","caller":"app/server.go:424","directory":"/tmp/testlib72298042"}
{"timestamp":"2024-09-30 07:35:38.995 Z","level":"info","msg":"Loaded config","caller":"app/server.go:425","source":"memory://"}
{"timestamp":"2024-09-30 07:35:39.255 Z","level":"debug","msg":"initElasticsearchChannelIndexCheck: calling elasticsearchChannelIndexCheckWithRetry before setting up config and license change listeners...","caller":"app/elasticsearch.go:21"}
{"timestamp":"2024-09-30 07:35:39.255 Z","level":"debug","msg":"elasticsearchChannelIndexCheckWithRetry: attempting to check channel index state...","caller":"app/elasticsearch.go:64"}
{"timestamp":"2024-09-30 07:35:39.255 Z","level":"debug","msg":"elasticsearchChannelIndexCheckWithRetry: skipping because elasticsearch indexing is disabled","caller":"app/elasticsearch.go:67"}
{"timestamp":"2024-09-30 07:35:39.288 Z","level":"debug","msg":"Fetching user count for first user account check","caller":"platform/config.go:356"}
{"timestamp":"2024-09-30 07:35:39.293 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 07:35:39.293 Z","level":"info","msg":"Starting up plugins","caller":"app/plugin.go:191"}
{"timestamp":"2024-09-30 07:35:39.294 Z","level":"debug","msg":"Enabling plugin health check job","caller":"plugin/environment.go:661","interval_s":"30s"}
{"timestamp":"2024-09-30 07:35:39.294 Z","level":"info","msg":"Syncing plugins from the file store","caller":"app/plugin.go:268"}
{"timestamp":"2024-09-30 07:35:39.294 Z","level":"debug","msg":"Plugin health check job starting.","caller":"plugin/health_check.go:31"}
{"timestamp":"2024-09-30 07:35:39.294 Z","level":"info","msg":"No plugins to sync from the file store","caller":"app/plugin.go:311"}
{"timestamp":"2024-09-30 07:35:39.294 Z","level":"debug","msg":"No prepackaged plugins directory found","caller":"app/plugin.go:912"}
{"timestamp":"2024-09-30 07:35:39.294 Z","level":"debug","msg":"Not persisting transitionally prepackaged plugins: none found","caller":"app/plugin.go:1184"}
{"timestamp":"2024-09-30 07:35:39.299 Z","level":"debug","msg":"Able to write files to local storage.","caller":"filestore/localstore.go:82"}
{"timestamp":"2024-09-30 07:35:39.317 Z","level":"info","msg":"Starting Server...","caller":"app/server.go:887"}
{"timestamp":"2024-09-30 07:35:39.317 Z","level":"info","msg":"Server is listening on 127.0.0.1:38441","caller":"app/server.go:963","address":"127.0.0.1:38441"}
{"timestamp":"2024-09-30 07:35:39.318 Z","level":"debug","msg":"No license provided; Remote Cluster services disabled","caller":"app/server.go:580"}
{"timestamp":"2024-09-30 07:35:39.375 Z","level":"debug","msg":"Initializing web routes","caller":"web/web.go:26"}
{"timestamp":"2024-09-30 07:35:39.376 Z","level":"debug","msg":"Skipping update to assets subpath since CI build","caller":"utils/subpath.go:187"}
{"timestamp":"2024-09-30 07:35:39.376 Z","level":"debug","msg":"Using client directory","caller":"web/static.go:34","clientDir":"/tmp/testlib72298042/client"}
{"timestamp":"2024-09-30 07:35:39.377 Z","level":"debug","msg":"Configured Client4 bool string values","caller":"api4/apitestlib.go:212","true":"TRUE","false":"F"}
{"timestamp":"2024-09-30 07:35:40.237 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users/login","request_id":"dzfcribbdfrip87aph9icmwy6r","user_id":"cyhudsm7w7ykmyxj35ftz3coow","status_code":"200"}
{"timestamp":"2024-09-30 07:35:40.237 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users/login","request_id":"n6cua9kwi3gsbqjo36wtwb549a","user_id":"yzq1wj7a5ir57x6tads7oexx6a","status_code":"200"}
{"timestamp":"2024-09-30 07:35:40.271 Z","level":"debug","msg":"Fetching user count for first user account check","caller":"platform/config.go:356"}
{"timestamp":"2024-09-30 07:35:40.276 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 07:35:40.287 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/ldap/sync","request_id":"eeomh4aqntndijhq9x4mixm1co","user_id":"","status_code":"200"}
{"timestamp":"2024-09-30 07:35:40.290 Z","level":"debug","msg":"You do not have the appropriate permissions.","caller":"web/context.go:120","path":"/api/v4/ldap/sync","request_id":"uqznox1i3frtxjxpco6jxnauxy","ip_addr":"127.0.0.1","user_id":"cyhudsm7w7ykmyxj35ftz3coow","method":"POST","err_where":"Permissions","http_code":403,"error":"Permissions: You do not have the appropriate permissions., userId=cyhudsm7w7ykmyxj35ftz3coow, permission=create_ldap_sync_job"}
{"timestamp":"2024-09-30 07:35:40.290 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/ldap/sync","request_id":"uqznox1i3frtxjxpco6jxnauxy","user_id":"cyhudsm7w7ykmyxj35ftz3coow","status_code":"403"}
{"timestamp":"2024-09-30 07:35:40.291 Z","level":"info","msg":"Purging all caches","caller":"platform/cluster_handlers.go:114"}
{"timestamp":"2024-09-30 07:35:40.293 Z","level":"info","msg":"License key has not been uploaded. Loading license key from disk.","caller":"utils/license.go:107","filename":"/tmp/testlib72298042/config/mattermost.mattermost-license"}
{"timestamp":"2024-09-30 07:35:40.293 Z","level":"warn","msg":"Failed to get license from disk","caller":"platform/license.go:93","error":"We could not find the license key on disk at /tmp/testlib72298042/config/mattermost.mattermost-license: stat /tmp/testlib72298042/config/mattermost.mattermost-license: no such file or directory"}
{"timestamp":"2024-09-30 07:35:40.294 Z","level":"warn","msg":"License key from https://mattermost.com required to unlock enterprise features.","caller":"platform/license.go:105","error":"resource \"License\" not found, id: "}
{"timestamp":"2024-09-30 07:35:40.297 Z","level":"info","msg":"Stopping Server...","caller":"app/server.go:669"}
{"timestamp":"2024-09-30 07:35:40.299 Z","level":"info","msg":"Shutting down Email batching service...","caller":"email/service.go:85"}
{"timestamp":"2024-09-30 07:35:40.299 Z","level":"info","msg":"Shutting down plugins","caller":"app/plugin.go:362"}
{"timestamp":"2024-09-30 07:35:40.299 Z","level":"debug","msg":"Disabling plugin health check job","caller":"plugin/environment.go:670"}
{"timestamp":"2024-09-30 07:35:40.299 Z","level":"info","msg":"stopping websocket hub connections","caller":"platform/web_hub.go:127"}
{"timestamp":"2024-09-30 07:35:40.300 Z","level":"info","msg":"Server stopped","caller":"app/server.go:753"}
--- FAIL: TestSyncLdap (1.41s)

Check failure on line 1 in com/mattermost/mattermost/server/v8/channels/api4

See this annotation in the file changed.

@github-actions github-actions / Postgres (Results)

com/mattermost/mattermost/server/v8/channels/api4.TestWebSocketReconnectRace

Failed
Raw output
=== RUN   TestWebSocketReconnectRace
{"timestamp":"2024-09-30 08:02:47.696 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 08:02:47.696 Z","level":"info","msg":"Successfully connected to cache backend","caller":"platform/service.go:191","backend":"redis","result":"PONG"}
{"timestamp":"2024-09-30 08:02:47.696 Z","level":"info","msg":"Server is initializing...","caller":"platform/service.go:194","go_version":"go1.22.6"}
{"timestamp":"2024-09-30 08:02:47.698 Z","level":"info","msg":"Starting websocket hubs","caller":"platform/web_hub.go:106","number_of_hubs":4}
{"timestamp":"2024-09-30 08:02:47.698 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":1}
{"timestamp":"2024-09-30 08:02:47.698 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":3}
{"timestamp":"2024-09-30 08:02:47.698 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":0}
{"timestamp":"2024-09-30 08:02:47.698 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":2}
{"timestamp":"2024-09-30 08:02:47.699 Z","level":"info","msg":"Loaded system translations","caller":"i18n/i18n.go:175","for locale":"en","from locale":"/mattermost/server/i18n/en.json"}
{"timestamp":"2024-09-30 08:02:47.706 Z","level":"info","msg":"Ensuring the telemetry ID..","caller":"telemetry/telemetry.go:147"}
{"timestamp":"2024-09-30 08:02:47.707 Z","level":"info","msg":"telemetry ID is set","caller":"telemetry/telemetry.go:157","id":"qinejcknobyqzj3ck1osmhauny"}
{"timestamp":"2024-09-30 08:02:47.726 Z","level":"error","msg":"SiteURL must be set. Some features will operate incorrectly if the SiteURL is not set. See documentation for details: https://mattermost.com/pl/configure-site-url","caller":"app/server.go:390"}
{"timestamp":"2024-09-30 08:02:47.726 Z","level":"info","msg":"Current version is 10.1.0 (///)","caller":"app/server.go:404","current_version":"10.1.0","build_number":"","build_date":"","build_hash":"","build_hash_enterprise":"","service_environment":"dev"}
{"timestamp":"2024-09-30 08:02:47.726 Z","level":"info","msg":"Team Edition Build","caller":"app/server.go:420","enterprise_build":false}
{"timestamp":"2024-09-30 08:02:47.726 Z","level":"info","msg":"Printing current working","caller":"app/server.go:424","directory":"/tmp/testlib72298042"}
{"timestamp":"2024-09-30 08:02:47.726 Z","level":"info","msg":"Loaded config","caller":"app/server.go:425","source":"memory://"}
{"timestamp":"2024-09-30 08:02:47.874 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"","conn_id":"hfjhgwwpa7yktn3aagmxmkctxo","origin_client":"web","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"timestamp":"2024-09-30 08:02:47.874 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"","conn_id":"j1johb1t878nfjw9bb8g88wpoo","origin_client":"web","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"timestamp":"2024-09-30 08:02:47.874 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"","conn_id":"fifyd3c953fdbfi75zd6ngmwah","origin_client":"web","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"timestamp":"2024-09-30 08:02:47.874 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"pk7xypzkgty7jjuc3gusff4jao","user_id":""}
{"timestamp":"2024-09-30 08:02:47.874 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"gdo48f38aig5uxec1bwgf1mfma","user_id":""}
{"timestamp":"2024-09-30 08:02:47.875 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"f81e478ee3r65rx7793zsju3jw","user_id":""}
{"timestamp":"2024-09-30 08:02:47.963 Z","level":"debug","msg":"initElasticsearchChannelIndexCheck: calling elasticsearchChannelIndexCheckWithRetry before setting up config and license change listeners...","caller":"app/elasticsearch.go:21"}
{"timestamp":"2024-09-30 08:02:47.963 Z","level":"debug","msg":"elasticsearchChannelIndexCheckWithRetry: attempting to check channel index state...","caller":"app/elasticsearch.go:64"}
{"timestamp":"2024-09-30 08:02:47.963 Z","level":"debug","msg":"elasticsearchChannelIndexCheckWithRetry: skipping because elasticsearch indexing is disabled","caller":"app/elasticsearch.go:67"}
{"timestamp":"2024-09-30 08:02:47.996 Z","level":"debug","msg":"Fetching user count for first user account check","caller":"platform/config.go:356"}
{"timestamp":"2024-09-30 08:02:48.001 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 08:02:48.001 Z","level":"info","msg":"Starting up plugins","caller":"app/plugin.go:191"}
{"timestamp":"2024-09-30 08:02:48.002 Z","level":"debug","msg":"Enabling plugin health check job","caller":"plugin/environment.go:661","interval_s":"30s"}
{"timestamp":"2024-09-30 08:02:48.002 Z","level":"info","msg":"Syncing plugins from the file store","caller":"app/plugin.go:268"}
{"timestamp":"2024-09-30 08:02:48.002 Z","level":"debug","msg":"Plugin health check job starting.","caller":"plugin/health_check.go:31"}
{"timestamp":"2024-09-30 08:02:48.002 Z","level":"info","msg":"No plugins to sync from the file store","caller":"app/plugin.go:311"}
{"timestamp":"2024-09-30 08:02:48.002 Z","level":"debug","msg":"No prepackaged plugins directory found","caller":"app/plugin.go:912"}
{"timestamp":"2024-09-30 08:02:48.002 Z","level":"debug","msg":"Not persisting transitionally prepackaged plugins: none found","caller":"app/plugin.go:1184"}
{"timestamp":"2024-09-30 08:02:48.006 Z","level":"debug","msg":"Able to write files to local storage.","caller":"filestore/localstore.go:82"}
{"timestamp":"2024-09-30 08:02:48.024 Z","level":"info","msg":"Starting Server...","caller":"app/server.go:887"}
{"timestamp":"2024-09-30 08:02:48.024 Z","level":"info","msg":"Server is listening on 127.0.0.1:39067","caller":"app/server.go:963","address":"127.0.0.1:39067"}
{"timestamp":"2024-09-30 08:02:48.025 Z","level":"debug","msg":"No license provided; Remote Cluster services disabled","caller":"app/server.go:580"}
{"timestamp":"2024-09-30 08:02:48.081 Z","level":"debug","msg":"Initializing web routes","caller":"web/web.go:26"}
{"timestamp":"2024-09-30 08:02:48.082 Z","level":"debug","msg":"Skipping update to assets subpath since CI build","caller":"utils/subpath.go:187"}
{"timestamp":"2024-09-30 08:02:48.083 Z","level":"debug","msg":"Using client directory","caller":"web/static.go:34","clientDir":"/tmp/testlib72298042/client"}
{"timestamp":"2024-09-30 08:02:48.083 Z","level":"debug","msg":"Configured Client4 bool string values","caller":"api4/apitestlib.go:212","true":"T","false":"F"}
{"timestamp":"2024-09-30 08:02:48.934 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users/login","request_id":"micc63kjdf8gf89qnams66oj6c","user_id":"yzq1wj7a5ir57x6tads7oexx6a","status_code":"200"}
{"timestamp":"2024-09-30 08:02:48.937 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users/login","request_id":"kzsdof31otfk3p1oi13dsyyo4a","user_id":"cyhudsm7w7ykmyxj35ftz3coow","status_code":"200"}
{"timestamp":"2024-09-30 08:02:48.991 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/teams","request_id":"46msfin45tdiiksmah56k8ohby","user_id":"cyhudsm7w7ykmyxj35ftz3coow","status_code":"201"}
{"timestamp":"2024-09-30 08:02:49.008 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/channels","request_id":"up51zrx7it878rmkjepo6xurqy","user_id":"cyhudsm7w7ykmyxj35ftz3coow","status_code":"201"}
{"timestamp":"2024-09-30 08:02:49.024 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/channels","request_id":"c1gt3kecffrf5mkbscwe39k5ao","user_id":"cyhudsm7w7ykmyxj35ftz3coow","status_code":"201"}
{"timestamp":"2024-09-30 08:02:49.040 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/channels","request_id":"puci7bbj1ide8gsifmpmch79ea","user_id":"cyhudsm7w7ykmyxj35ftz3coow","status_code":"201"}
{"timestamp":"2024-09-30 08:02:49.056 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/channels","request_id":"56a9y899dj8q78kr8hst9oom3o","user_id":"cyhudsm7w7ykmyxj35ftz3coow","status_code":"201"}
{"timestamp":"2024-09-30 08:02:49.072 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/channels","request_id":"k894cesqbffx9pcu71neut3ypy","user_id":"cyhudsm7w7ykmyxj35ftz3coow","status_code":"201"}
{"timestamp":"2024-09-30 08:02:49.083 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/posts","request_id":"pnd9q9szb3f6fbagwcrqsc8yre","user_id":"cyhudsm7w7ykmyxj35ftz3coow","status_code":"201"}
{"timestamp":"2024-09-30 08:02:49.233 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"DELETE","url":"/api/v4/channels/cs4icq747tnizjypy17mh83hge","request_id":"4c9mtgj6ztd5jm6qkrmktqp3ya","user_id":"cyhudsm7w7ykmyxj35ftz3coow","status_code":"200"}
{"timestamp":"2024-09-30 08:02:50.069 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users/login","request_id":"f9856wzt43faff94jw677qu3nw","user_id":"hrigh9f5xtromk1e5o4q61s5ec","status_code":"200"}
{"timestamp":"2024-09-30 08:02:50.074 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"hrigh9f5xtromk1e5o4q61s5ec","conn_id":"zsicjmw1spnw3c5mrf7e4jyfih","origin_client":"web","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"timestamp":"2024-09-30 08:02:50.074 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"7p3q4i5bjpr3mk4i33djx4543h","user_id":""}
{"timestamp":"2024-09-30 08:02:50.081 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"hrigh9f5xtromk1e5o4q61s5ec","conn_id":"zsicjmw1spnw3c5mrf7e4jyfih","origin_client":"web","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"timestamp":"2024-09-30 08:02:50.082 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"hrigh9f5xtromk1e5o4q61s5ec","conn_id":"y6pe6x9gz3y47km6tcjxt9fx8e","origin_client":"web","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"timestamp":"2024-09-30 08:02:50.082 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"hrigh9f5xtromk1e5o4q61s5ec","conn_id":"ty81oxgbgtbuuragmt8raxif7c","origin_client":"web","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
==================
WARNING: DATA RACE
Write at 0x00c0062db860 by goroutine 870212:
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).ReturnSessionToPool()
      /mattermost/server/channels/app/platform/session.go:19 +0x9c
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*hubConnectionIndex).Remove()
      /mattermost/server/channels/app/platform/web_hub.go:651 +0x41
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*hubConnectionIndex).RemoveInactiveByConnectionID()
      /mattermost/server/channels/app/platform/web_hub.go:725 +0x2c7
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*Hub).Start.func1()
      /mattermost/server/channels/app/platform/web_hub.go:409 +0x8f4
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*Hub).Start.func2()
      /mattermost/server/channels/app/platform/web_hub.go:587 +0x58

Previous read at 0x00c0062db860 by goroutine 871403:
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).NewWebConn.func1()
      /mattermost/server/channels/app/platform/web_conn.go:258 +0xbc
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).Go.func1()
      /mattermost/server/channels/app/platform/goroutines.go:14 +0x37

Goroutine 870212 (running) created at:
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*Hub).Start()
      /mattermost/server/channels/app/platform/web_hub.go:604 +0x264
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).hubStart()
      /mattermost/server/channels/app/platform/web_hub.go:114 +0x29b
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).Start()
      /mattermost/server/channels/app/platform/service.go:377 +0x3a
  github.com/mattermost/mattermost/server/v8/channels/app.NewServer()
      /mattermost/server/channels/app/server.go:240 +0x16e6
  github.com/mattermost/mattermost/server/v8/channels/api4.setupTestHelper()
      /mattermost/server/channels/api4/apitestlib.go:148 +0x148c
  github.com/mattermost/mattermost/server/v8/channels/api4.Setup()
      /mattermost/server/channels/api4/apitestlib.go:268 +0x1fc
  github.com/mattermost/mattermost/server/v8/channels/api4.TestWebSocketReconnectRace()
      /mattermost/server/channels/api4/websocket_test.go:207 +0x45
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /usr/local/go/src/testing/testing.go:1742 +0x44

Goroutine 871403 (running) created at:
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).Go()
      /mattermost/server/channels/app/platform/goroutines.go:13 +0xec
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).NewWebConn()
      /mattermost/server/channels/app/platform/web_conn.go:254 +0xf93
  github.com/mattermost/mattermost/server/v8/channels/api4.connectWebSocket()
      /mattermost/server/channels/api4/websocket.go:79 +0x133c
  github.com/mattermost/mattermost/server/v8/channels/web.Handler.ServeHTTP()
      /mattermost/server/channels/web/handlers.go:387 +0x6645
  github.com/mattermost/mattermost/server/v8/channels/web.(*Handler).ServeHTTP()
      <autogenerated>:1 +0xe7
  github.com/klauspost/compress/gzhttp.NewWrapper.func1.1()
      /go/pkg/mod/github.com/klauspost/[email protected]/gzhttp/compress.go:501 +0x6e1
  net/http.HandlerFunc.ServeHTTP()
      /usr/local/go/src/net/http/server.go:2171 +0x47
  github.com/gorilla/mux.(*Router).ServeHTTP()
      /go/pkg/mod/github.com/gorilla/[email protected]/mux.go:212 +0x371
  net/http.serverHandler.ServeHTTP()
      /usr/local/go/src/net/http/server.go:3142 +0x2a1
  net/http.(*conn).serve()
      /usr/local/go/src/net/http/server.go:2044 +0x13c4
  net/http.(*Server).Serve.gowrap3()
      /usr/local/go/src/net/http/server.go:3290 +0x4f
==================
{"timestamp":"2024-09-30 08:02:50.083 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"hrigh9f5xtromk1e5o4q61s5ec","conn_id":"frqrh4o4dfrtuqt4kzdf5r196y","origin_client":"web","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"timestamp":"2024-09-30 08:02:50.083 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"hrigh9f5xtromk1e5o4q61s5ec","conn_id":"74yzj8rg53g8jjk7sxukffqe5h","origin_client":"web","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"timestamp":"2024-09-30 08:02:50.084 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"3fw6ht34ujdktxzzysq79brbyo","user_id":"hrigh9f5xtromk1e5o4q61s5ec"}
{"timestamp":"2024-09-30 08:02:50.084 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"hrigh9f5xtromk1e5o4q61s5ec","conn_id":"h9ooo53ko3rfub5k5d1949dd7y","origin_client":"web","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"timestamp":"2024-09-30 08:02:50.084 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"hrigh9f5xtromk1e5o4q61s5ec","conn_id":"xts694c4efrhbmf8cimhnrx7jc","origin_client":"web","error":"read tcp 127.0.0.1:39067->127.0.0.1:59604: read: connection reset by peer"}
{"timestamp":"2024-09-30 08:02:50.084 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"pkxjsckrnfn1ur1otz77ezbm9c","user_id":"hrigh9f5xtromk1e5o4q61s5ec"}
{"timestamp":"2024-09-30 08:02:50.084 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"69jwsjnrmiyi8ecaicbybjkxrw","user_id":"hrigh9f5xtromk1e5o4q61s5ec"}
{"timestamp":"2024-09-30 08:02:50.084 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"hrigh9f5xtromk1e5o4q61s5ec","conn_id":"zsicjmw1spnw3c5mrf7e4jyfih","origin_client":"web","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"timestamp":"2024-09-30 08:02:50.084 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"q5y9z7sjobfcfm7hjk8pkhn98c","user_id":"hrigh9f5xtromk1e5o4q61s5ec"}
{"timestamp":"2024-09-30 08:02:50.084 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"woqn8smdpj8n3kd9rh7zgz7i1r","user_id":"hrigh9f5xtromk1e5o4q61s5ec"}
{"timestamp":"2024-09-30 08:02:50.084 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"a55tnktc978umqen1sr9e5z6xy","user_id":"hrigh9f5xtromk1e5o4q61s5ec"}
{"timestamp":"2024-09-30 08:02:50.084 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"hrigh9f5xtromk1e5o4q61s5ec","conn_id":"jmaajkq853ytfgj8kneia65imh","origin_client":"web","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"timestamp":"2024-09-30 08:02:50.085 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"c1z4u53jpibmddzwyajxdtgsmc","user_id":"hrigh9f5xtromk1e5o4q61s5ec"}
{"timestamp":"2024-09-30 08:02:50.085 Z","level":"info","msg":"Purging all caches","caller":"platform/cluster_handlers.go:114"}
{"timestamp":"2024-09-30 08:02:50.085 Z","level":"debug","msg":"websocket.NextReader: closing websocket","caller":"platform/web_conn.go:991","user_id":"hrigh9f5xtromk1e5o4q61s5ec","conn_id":"wc8o3kgbmfb58poog5foiwb5ue","origin_client":"web","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"timestamp":"2024-09-30 08:02:50.085 Z","level":"debug","msg":"websocket.drainDeadQueue: closing websocket","caller":"platform/web_conn.go:991","user_id":"hrigh9f5xtromk1e5o4q61s5ec","conn_id":"zsicjmw1spnw3c5mrf7e4jyfih","origin_client":"web","error":"write tcp 127.0.0.1:39067->127.0.0.1:59608: use of closed network connection"}
{"timestamp":"2024-09-30 08:02:50.085 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"xcutqhw1q3yx9867ixfaxmbpae","user_id":"hrigh9f5xtromk1e5o4q61s5ec"}
{"timestamp":"2024-09-30 08:02:50.085 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"ft1zcb35oiyjfmkd33dxggu1oc","user_id":"hrigh9f5xtromk1e5o4q61s5ec"}
{"timestamp":"2024-09-30 08:02:50.085 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"GET","url":"/api/v4/websocket","request_id":"yednzojdajdcj8doggku13o7kr","user_id":"hrigh9f5xtromk1e5o4q61s5ec"}
{"timestamp":"2024-09-30 08:02:50.088 Z","level":"info","msg":"License key has not been uploaded. Loading license key from disk.","caller":"utils/license.go:107","filename":"/tmp/testlib72298042/config/mattermost.mattermost-license"}
{"timestamp":"2024-09-30 08:02:50.088 Z","level":"warn","msg":"Failed to get license from disk","caller":"platform/license.go:93","error":"We could not find the license key on disk at /tmp/testlib72298042/config/mattermost.mattermost-license: stat /tmp/testlib72298042/config/mattermost.mattermost-license: no such file or directory"}
{"timestamp":"2024-09-30 08:02:50.089 Z","level":"warn","msg":"License key from https://mattermost.com required to unlock enterprise features.","caller":"platform/license.go:105","error":"resource \"License\" not found, id: "}
{"timestamp":"2024-09-30 08:02:50.092 Z","level":"info","msg":"Stopping Server...","caller":"app/server.go:669"}
{"timestamp":"2024-09-30 08:02:50.094 Z","level":"info","msg":"Shutting down Email batching service...","caller":"email/service.go:85"}
{"timestamp":"2024-09-30 08:02:50.094 Z","level":"info","msg":"Shutting down plugins","caller":"app/plugin.go:362"}
{"timestamp":"2024-09-30 08:02:50.094 Z","level":"debug","msg":"Disabling plugin health check job","caller":"plugin/environment.go:670"}
{"timestamp":"2024-09-30 08:02:50.095 Z","level":"info","msg":"stopping websocket hub connections","caller":"platform/web_hub.go:127"}
{"timestamp":"2024-09-30 08:02:50.100 Z","level":"info","msg":"Server stopped","caller":"app/server.go:753"}
    testing.go:1398: race detected during execution of test
--- FAIL: TestWebSocketReconnectRace (2.48s)

Check failure on line 1 in com/mattermost/mattermost/server/v8/channels/api4

See this annotation in the file changed.

@github-actions github-actions / Postgres (Results)

com/mattermost/mattermost/server/v8/channels/api4.TestSyncLdap/SystemAdminClient#01

Failed
Raw output
=== RUN   TestSyncLdap/SystemAdminClient#01
{"timestamp":"2024-09-30 08:28:48.262 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/ldap/sync","request_id":"66q5zqsybinqbnh4ico8tjzwxy","user_id":"c6m6o5yx9pg1ik84toj9a4x9me","status_code":"200"}
==================
WARNING: DATA RACE
Read at 0x00c002297680 by goroutine 1200:
  reflect.maplen()
      /usr/local/go/src/runtime/map.go:1406 +0x0
  reflect.Value.lenNonSlice()
      /usr/local/go/src/reflect/value.go:1785 +0x1e9
  reflect.Value.Len()
      /usr/local/go/src/reflect/value.go:1774 +0x137
  internal/fmtsort.Sort()
      /usr/local/go/src/internal/fmtsort/sort.go:58 +0x121
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:816 +0x1144
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:853 +0x1d3e
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:853 +0x1d3e
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:921 +0x132a
  fmt.(*pp).printArg()
      /usr/local/go/src/fmt/print.go:759 +0xb84
  fmt.(*pp).doPrintf()
      /usr/local/go/src/fmt/print.go:1174 +0x10ce
  fmt.Sprintf()
      /usr/local/go/src/fmt/print.go:239 +0x5c
  github.com/stretchr/testify/mock.Arguments.Diff()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:939 +0x1b2
  github.com/stretchr/testify/mock.(*Mock).findExpectedCall()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:368 +0x147
  github.com/stretchr/testify/mock.(*Mock).MethodCalled()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:476 +0xac
  github.com/stretchr/testify/mock.(*Mock).Called()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:466 +0x195
  github.com/mattermost/mattermost/server/v8/einterfaces/mocks.(*LdapInterface).StartSynchronizeJob()
      /mattermost/server/einterfaces/mocks/LdapInterface.go:406 +0x1b0
  github.com/mattermost/mattermost/server/v8/channels/app.(*App).SyncLdap.func1()
      /mattermost/server/channels/app/ldap.go:33 +0x1d8
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).Go.func1()
      /mattermost/server/channels/app/platform/goroutines.go:14 +0x37

Previous write at 0x00c002297680 by goroutine 1153:
  runtime.mapclear()
      /usr/local/go/src/runtime/map.go:989 +0x0
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).ReturnSessionToPool()
      /mattermost/server/channels/app/platform/session.go:25 +0xcf
  github.com/mattermost/mattermost/server/v8/channels/app.(*App).ReturnSessionToPool()
      /mattermost/server/channels/app/session.go:227 +0x26
  github.com/mattermost/mattermost/server/v8/channels/web.Handler.ServeHTTP.deferwrap1()
      /mattermost/server/channels/web/handlers.go:295 +0x55
  runtime.deferreturn()
      /usr/local/go/src/runtime/panic.go:602 +0x5d
  github.com/mattermost/mattermost/server/v8/channels/web.(*Handler).ServeHTTP()
      <autogenerated>:1 +0xe7
  github.com/klauspost/compress/gzhttp.NewWrapper.func1.1()
      /go/pkg/mod/github.com/klauspost/[email protected]/gzhttp/compress.go:495 +0x7c6
  net/http.HandlerFunc.ServeHTTP()
      /usr/local/go/src/net/http/server.go:2171 +0x47
  github.com/gorilla/mux.(*Router).ServeHTTP()
      /go/pkg/mod/github.com/gorilla/[email protected]/mux.go:212 +0x371
  net/http.serverHandler.ServeHTTP()
      /usr/local/go/src/net/http/server.go:3142 +0x2a1
  net/http.(*conn).serve()
      /usr/local/go/src/net/http/server.go:2044 +0x13c4
  net/http.(*Server).Serve.gowrap3()
      /usr/local/go/src/net/http/server.go:3290 +0x4f

Goroutine 1200 (running) created at:
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).Go()
      /mattermost/server/channels/app/platform/goroutines.go:13 +0xec
  github.com/mattermost/mattermost/server/v8/channels/app.(*Server).Go()
      /mattermost/server/channels/app/server.go:806 +0x148
  github.com/mattermost/mattermost/server/v8/channels/app.(*App).SyncLdap()
      /mattermost/server/channels/app/ldap.go:21 +0x5d
  github.com/mattermost/mattermost/server/v8/channels/api4.syncLdap()
      /mattermost/server/channels/api4/ldap.go:69 +0x9de
  github.com/mattermost/mattermost/server/v8/channels/web.Handler.ServeHTTP()
      /mattermost/server/channels/web/handlers.go:387 +0x6645
  github.com/mattermost/mattermost/server/v8/channels/web.(*Handler).ServeHTTP()
      <autogenerated>:1 +0xe7
  github.com/klauspost/compress/gzhttp.NewWrapper.func1.1()
      /go/pkg/mod/github.com/klauspost/[email protected]/gzhttp/compress.go:495 +0x7c6
  net/http.HandlerFunc.ServeHTTP()
      /usr/local/go/src/net/http/server.go:2171 +0x47
  github.com/gorilla/mux.(*Router).ServeHTTP()
      /go/pkg/mod/github.com/gorilla/[email protected]/mux.go:212 +0x371
  net/http.serverHandler.ServeHTTP()
      /usr/local/go/src/net/http/server.go:3142 +0x2a1
  net/http.(*conn).serve()
      /usr/local/go/src/net/http/server.go:2044 +0x13c4
  net/http.(*Server).Serve.gowrap3()
      /usr/local/go/src/net/http/server.go:3290 +0x4f

Goroutine 1153 (running) created at:
  net/http.(*Server).Serve()
      /usr/local/go/src/net/http/server.go:3290 +0x8ec
  github.com/mattermost/mattermost/server/v8/channels/app.(*Server).Start.func2()
      /mattermost/server/channels/app/server.go:1070 +0x224
==================
{"timestamp":"2024-09-30 08:28:48.265 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/ldap/sync","request_id":"nd4y3s53g3ni8d3u7q9s6qcfuy","user_id":"c6m6o5yx9pg1ik84toj9a4x9me","status_code":"200"}
    testing.go:1398: race detected during execution of test
--- FAIL: TestSyncLdap/SystemAdminClient#01 (0.01s)

Check failure on line 1 in com/mattermost/mattermost/server/v8/channels/api4

See this annotation in the file changed.

@github-actions github-actions / Postgres (Results)

com/mattermost/mattermost/server/v8/channels/api4.TestSyncLdap

Failed
Raw output
=== RUN   TestSyncLdap
{"timestamp":"2024-09-30 08:28:42.610 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 08:28:42.610 Z","level":"info","msg":"Successfully connected to cache backend","caller":"platform/service.go:191","backend":"redis","result":"PONG"}
{"timestamp":"2024-09-30 08:28:42.610 Z","level":"info","msg":"Server is initializing...","caller":"platform/service.go:194","go_version":"go1.22.6"}
{"timestamp":"2024-09-30 08:28:42.613 Z","level":"info","msg":"Starting websocket hubs","caller":"platform/web_hub.go:106","number_of_hubs":4}
{"timestamp":"2024-09-30 08:28:42.613 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":0}
{"timestamp":"2024-09-30 08:28:42.613 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":2}
{"timestamp":"2024-09-30 08:28:42.613 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":3}
{"timestamp":"2024-09-30 08:28:42.613 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":1}
{"timestamp":"2024-09-30 08:28:42.614 Z","level":"info","msg":"Loaded system translations","caller":"i18n/i18n.go:175","for locale":"en","from locale":"/mattermost/server/i18n/en.json"}
{"timestamp":"2024-09-30 08:28:42.623 Z","level":"info","msg":"Ensuring the telemetry ID..","caller":"telemetry/telemetry.go:147"}
{"timestamp":"2024-09-30 08:28:42.625 Z","level":"info","msg":"telemetry ID is set","caller":"telemetry/telemetry.go:157","id":"d5syjn6poibzz8iwmcwttmfntr"}
{"timestamp":"2024-09-30 08:28:42.650 Z","level":"error","msg":"SiteURL must be set. Some features will operate incorrectly if the SiteURL is not set. See documentation for details: https://mattermost.com/pl/configure-site-url","caller":"app/server.go:390"}
{"timestamp":"2024-09-30 08:28:42.650 Z","level":"info","msg":"Current version is 10.1.0 (///)","caller":"app/server.go:404","current_version":"10.1.0","build_number":"","build_date":"","build_hash":"","build_hash_enterprise":"","service_environment":"dev"}
{"timestamp":"2024-09-30 08:28:42.650 Z","level":"info","msg":"Team Edition Build","caller":"app/server.go:420","enterprise_build":false}
{"timestamp":"2024-09-30 08:28:42.650 Z","level":"info","msg":"Printing current working","caller":"app/server.go:424","directory":"/tmp/testlib3922655768"}
{"timestamp":"2024-09-30 08:28:42.650 Z","level":"info","msg":"Loaded config","caller":"app/server.go:425","source":"memory://"}
{"timestamp":"2024-09-30 08:28:42.907 Z","level":"debug","msg":"initElasticsearchChannelIndexCheck: calling elasticsearchChannelIndexCheckWithRetry before setting up config and license change listeners...","caller":"app/elasticsearch.go:21"}
{"timestamp":"2024-09-30 08:28:42.907 Z","level":"debug","msg":"elasticsearchChannelIndexCheckWithRetry: attempting to check channel index state...","caller":"app/elasticsearch.go:64"}
{"timestamp":"2024-09-30 08:28:42.907 Z","level":"debug","msg":"elasticsearchChannelIndexCheckWithRetry: skipping because elasticsearch indexing is disabled","caller":"app/elasticsearch.go:67"}
{"timestamp":"2024-09-30 08:28:42.939 Z","level":"debug","msg":"Fetching user count for first user account check","caller":"platform/config.go:356"}
{"timestamp":"2024-09-30 08:28:42.942 Z","level":"info","msg":"Post.Message has size restrictions","caller":"sqlstore/post_store.go:2615","max_characters":16383,"max_bytes":65535}
{"timestamp":"2024-09-30 08:28:42.947 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 08:28:42.947 Z","level":"info","msg":"Starting up plugins","caller":"app/plugin.go:191"}
{"timestamp":"2024-09-30 08:28:42.947 Z","level":"debug","msg":"Enabling plugin health check job","caller":"plugin/environment.go:661","interval_s":"30s"}
{"timestamp":"2024-09-30 08:28:42.947 Z","level":"info","msg":"Syncing plugins from the file store","caller":"app/plugin.go:268"}
{"timestamp":"2024-09-30 08:28:42.947 Z","level":"debug","msg":"Plugin health check job starting.","caller":"plugin/health_check.go:31"}
{"timestamp":"2024-09-30 08:28:42.947 Z","level":"info","msg":"No plugins to sync from the file store","caller":"app/plugin.go:311"}
{"timestamp":"2024-09-30 08:28:42.948 Z","level":"debug","msg":"No prepackaged plugins directory found","caller":"app/plugin.go:912"}
{"timestamp":"2024-09-30 08:28:42.948 Z","level":"debug","msg":"Not persisting transitionally prepackaged plugins: none found","caller":"app/plugin.go:1184"}
{"timestamp":"2024-09-30 08:28:42.952 Z","level":"debug","msg":"Able to write files to local storage.","caller":"filestore/localstore.go:82"}
{"timestamp":"2024-09-30 08:28:42.970 Z","level":"info","msg":"Starting Server...","caller":"app/server.go:887"}
{"timestamp":"2024-09-30 08:28:42.970 Z","level":"info","msg":"Server is listening on 127.0.0.1:46627","caller":"app/server.go:963","address":"127.0.0.1:46627"}
{"timestamp":"2024-09-30 08:28:42.970 Z","level":"debug","msg":"No license provided; Remote Cluster services disabled","caller":"app/server.go:580"}
{"timestamp":"2024-09-30 08:28:43.029 Z","level":"debug","msg":"Initializing web routes","caller":"web/web.go:26"}
{"timestamp":"2024-09-30 08:28:43.030 Z","level":"debug","msg":"Skipping update to assets subpath since CI build","caller":"utils/subpath.go:187"}
{"timestamp":"2024-09-30 08:28:43.030 Z","level":"debug","msg":"Using client directory","caller":"web/static.go:34","clientDir":"/tmp/testlib3922655768/client"}
{"timestamp":"2024-09-30 08:28:43.030 Z","level":"debug","msg":"Configured Client4 bool string values","caller":"api4/apitestlib.go:212","true":"t","false":"False"}
{"timestamp":"2024-09-30 08:28:43.033 Z","level":"debug","msg":"Fetching user count for first user account check","caller":"platform/config.go:356"}
{"timestamp":"2024-09-30 08:28:43.874 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"s67mk3hqd3gd5frh9guazgqh9y@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:28:43.892 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"ujxtbg4tb3nszftdr8b5q1ty5h","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:28:43.905 Z","level":"debug","msg":"Fetching user count for first user account check","caller":"platform/config.go:356"}
{"timestamp":"2024-09-30 08:28:44.747 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"kibube7n6bd4jqwzhc137msawo@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:28:44.764 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"safrsy7y778y3bow7b6fx9eaka","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:28:45.610 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"6sj5jr6rajn1xb7twwn4f9joiw@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:28:45.627 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"nt47ho5srpfixx3xmyatf99qxr","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:28:46.467 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"ni48qgos3jreuc7c99ze7pmazy@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:28:46.487 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"ki3ie11adbgg3doa69o7udkb9o","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:28:47.345 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"n8zc3a5x6i8opqgfa7zg3jhqme@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:28:47.361 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"4n1yb4jjibbob88t1j5rtwoz6o","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:28:48.219 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users/login","request_id":"d3fhbdrtrbf88rbzc3uw5r87iw","user_id":"c6m6o5yx9pg1ik84toj9a4x9me","status_code":"200"}
{"timestamp":"2024-09-30 08:28:48.219 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users/login","request_id":"ifzgjmnrhtyybdt57x4xziz4uh","user_id":"7inp1mqguidxjfecqicace7bjw","status_code":"200"}
{"timestamp":"2024-09-30 08:28:48.260 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 08:28:48.267 Z","level":"debug","msg":"You do not have the appropriate permissions.","caller":"web/context.go:120","path":"/api/v4/ldap/sync","request_id":"sb4w49wrb7g43n5hzsawpsxs7h","ip_addr":"127.0.0.1","user_id":"7inp1mqguidxjfecqicace7bjw","method":"POST","err_where":"Permissions","http_code":403,"error":"Permissions: You do not have the appropriate permissions., userId=7inp1mqguidxjfecqicace7bjw, permission=create_ldap_sync_job"}
{"timestamp":"2024-09-30 08:28:48.268 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/ldap/sync","request_id":"sb4w49wrb7g43n5hzsawpsxs7h","user_id":"7inp1mqguidxjfecqicace7bjw","status_code":"403"}
{"timestamp":"2024-09-30 08:28:48.268 Z","level":"info","msg":"Purging all caches","caller":"platform/cluster_handlers.go:114"}
{"timestamp":"2024-09-30 08:28:48.271 Z","level":"info","msg":"License key has not been uploaded. Loading license key from disk.","caller":"utils/license.go:107","filename":"/tmp/testlib3922655768/config/mattermost.mattermost-license"}
{"timestamp":"2024-09-30 08:28:48.271 Z","level":"warn","msg":"Failed to get license from disk","caller":"platform/license.go:93","error":"We could not find the license key on disk at /tmp/testlib3922655768/config/mattermost.mattermost-license: stat /tmp/testlib3922655768/config/mattermost.mattermost-license: no such file or directory"}
{"timestamp":"2024-09-30 08:28:48.271 Z","level":"warn","msg":"License key from https://mattermost.com required to unlock enterprise features.","caller":"platform/license.go:105","error":"resource \"License\" not found, id: "}
{"timestamp":"2024-09-30 08:28:48.274 Z","level":"info","msg":"Stopping Server...","caller":"app/server.go:669"}
{"timestamp":"2024-09-30 08:28:48.277 Z","level":"info","msg":"Shutting down Email batching service...","caller":"email/service.go:85"}
{"timestamp":"2024-09-30 08:28:48.277 Z","level":"info","msg":"Shutting down plugins","caller":"app/plugin.go:362"}
{"timestamp":"2024-09-30 08:28:48.277 Z","level":"debug","msg":"Disabling plugin health check job","caller":"plugin/environment.go:670"}
{"timestamp":"2024-09-30 08:28:48.277 Z","level":"info","msg":"stopping websocket hub connections","caller":"platform/web_hub.go:127"}
{"timestamp":"2024-09-30 08:28:48.279 Z","level":"info","msg":"Server stopped","caller":"app/server.go:753"}
--- FAIL: TestSyncLdap (5.75s)

Check failure on line 1 in com/mattermost/mattermost/server/v8/channels/api4

See this annotation in the file changed.

@github-actions github-actions / Postgres (Results)

com/mattermost/mattermost/server/v8/channels/api4.TestSyncLdap/SystemAdminClient#01

Failed
Raw output
=== RUN   TestSyncLdap/SystemAdminClient#01
{"timestamp":"2024-09-30 08:29:12.203 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/ldap/sync","request_id":"kmkc6nziatgspfxofuopneyifo","user_id":"z1hfzzgqdjde3gm56auyqr5xyw","status_code":"200"}
==================
WARNING: DATA RACE
Read at 0x00c002f52c60 by goroutine 1201:
  reflect.maplen()
      /usr/local/go/src/runtime/map.go:1406 +0x0
  reflect.Value.lenNonSlice()
      /usr/local/go/src/reflect/value.go:1785 +0x1e9
  reflect.Value.Len()
      /usr/local/go/src/reflect/value.go:1774 +0x137
  internal/fmtsort.Sort()
      /usr/local/go/src/internal/fmtsort/sort.go:58 +0x121
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:816 +0x1144
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:853 +0x1d3e
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:853 +0x1d3e
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:921 +0x132a
  fmt.(*pp).printArg()
      /usr/local/go/src/fmt/print.go:759 +0xb84
  fmt.(*pp).doPrintf()
      /usr/local/go/src/fmt/print.go:1174 +0x10ce
  fmt.Sprintf()
      /usr/local/go/src/fmt/print.go:239 +0x5c
  github.com/stretchr/testify/mock.Arguments.Diff()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:939 +0x1b2
  github.com/stretchr/testify/mock.(*Mock).findExpectedCall()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:368 +0x147
  github.com/stretchr/testify/mock.(*Mock).MethodCalled()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:476 +0xac
  github.com/stretchr/testify/mock.(*Mock).Called()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:466 +0x195
  github.com/mattermost/mattermost/server/v8/einterfaces/mocks.(*LdapInterface).StartSynchronizeJob()
      /mattermost/server/einterfaces/mocks/LdapInterface.go:406 +0x1b0
  github.com/mattermost/mattermost/server/v8/channels/app.(*App).SyncLdap.func1()
      /mattermost/server/channels/app/ldap.go:33 +0x1d8
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).Go.func1()
      /mattermost/server/channels/app/platform/goroutines.go:14 +0x37

Previous write at 0x00c002f52c60 by goroutine 988:
  runtime.mapclear()
      /usr/local/go/src/runtime/map.go:989 +0x0
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).ReturnSessionToPool()
      /mattermost/server/channels/app/platform/session.go:25 +0xcf
  github.com/mattermost/mattermost/server/v8/channels/app.(*App).ReturnSessionToPool()
      /mattermost/server/channels/app/session.go:227 +0x26
  github.com/mattermost/mattermost/server/v8/channels/web.Handler.ServeHTTP.deferwrap1()
      /mattermost/server/channels/web/handlers.go:295 +0x55
  runtime.deferreturn()
      /usr/local/go/src/runtime/panic.go:602 +0x5d
  github.com/mattermost/mattermost/server/v8/channels/web.(*Handler).ServeHTTP()
      <autogenerated>:1 +0xe7
  github.com/klauspost/compress/gzhttp.NewWrapper.func1.1()
      /go/pkg/mod/github.com/klauspost/[email protected]/gzhttp/compress.go:495 +0x7c6
  net/http.HandlerFunc.ServeHTTP()
      /usr/local/go/src/net/http/server.go:2171 +0x47
  github.com/gorilla/mux.(*Router).ServeHTTP()
      /go/pkg/mod/github.com/gorilla/[email protected]/mux.go:212 +0x371
  net/http.serverHandler.ServeHTTP()
      /usr/local/go/src/net/http/server.go:3142 +0x2a1
  net/http.(*conn).serve()
      /usr/local/go/src/net/http/server.go:2044 +0x13c4
  net/http.(*Server).Serve.gowrap3()
      /usr/local/go/src/net/http/server.go:3290 +0x4f

Goroutine 1201 (running) created at:
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).Go()
      /mattermost/server/channels/app/platform/goroutines.go:13 +0xec
  github.com/mattermost/mattermost/server/v8/channels/app.(*Server).Go()
      /mattermost/server/channels/app/server.go:806 +0x148
  github.com/mattermost/mattermost/server/v8/channels/app.(*App).SyncLdap()
      /mattermost/server/channels/app/ldap.go:21 +0x5d
  github.com/mattermost/mattermost/server/v8/channels/api4.syncLdap()
      /mattermost/server/channels/api4/ldap.go:69 +0x9de
  github.com/mattermost/mattermost/server/v8/channels/web.Handler.ServeHTTP()
      /mattermost/server/channels/web/handlers.go:387 +0x6645
  github.com/mattermost/mattermost/server/v8/channels/web.(*Handler).ServeHTTP()
      <autogenerated>:1 +0xe7
  github.com/klauspost/compress/gzhttp.NewWrapper.func1.1()
      /go/pkg/mod/github.com/klauspost/[email protected]/gzhttp/compress.go:495 +0x7c6
  net/http.HandlerFunc.ServeHTTP()
      /usr/local/go/src/net/http/server.go:2171 +0x47
  github.com/gorilla/mux.(*Router).ServeHTTP()
      /go/pkg/mod/github.com/gorilla/[email protected]/mux.go:212 +0x371
  net/http.serverHandler.ServeHTTP()
      /usr/local/go/src/net/http/server.go:3142 +0x2a1
  net/http.(*conn).serve()
      /usr/local/go/src/net/http/server.go:2044 +0x13c4
  net/http.(*Server).Serve.gowrap3()
      /usr/local/go/src/net/http/server.go:3290 +0x4f

Goroutine 988 (running) created at:
  net/http.(*Server).Serve()
      /usr/local/go/src/net/http/server.go:3290 +0x8ec
  github.com/mattermost/mattermost/server/v8/channels/app.(*Server).Start.func2()
      /mattermost/server/channels/app/server.go:1070 +0x224
==================
{"timestamp":"2024-09-30 08:29:12.207 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/ldap/sync","request_id":"gh7phubts7ydxdfkhq7hbib81o","user_id":"z1hfzzgqdjde3gm56auyqr5xyw","status_code":"200"}
    testing.go:1398: race detected during execution of test
--- FAIL: TestSyncLdap/SystemAdminClient#01 (0.01s)

Check failure on line 1 in com/mattermost/mattermost/server/v8/channels/api4

See this annotation in the file changed.

@github-actions github-actions / Postgres (Results)

com/mattermost/mattermost/server/v8/channels/api4.TestSyncLdap

Failed
Raw output
=== RUN   TestSyncLdap
{"timestamp":"2024-09-30 08:29:06.560 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 08:29:06.560 Z","level":"info","msg":"Successfully connected to cache backend","caller":"platform/service.go:191","backend":"redis","result":"PONG"}
{"timestamp":"2024-09-30 08:29:06.560 Z","level":"info","msg":"Server is initializing...","caller":"platform/service.go:194","go_version":"go1.22.6"}
{"timestamp":"2024-09-30 08:29:06.562 Z","level":"info","msg":"Starting websocket hubs","caller":"platform/web_hub.go:106","number_of_hubs":4}
{"timestamp":"2024-09-30 08:29:06.562 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":0}
{"timestamp":"2024-09-30 08:29:06.562 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":1}
{"timestamp":"2024-09-30 08:29:06.562 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":2}
{"timestamp":"2024-09-30 08:29:06.562 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":3}
{"timestamp":"2024-09-30 08:29:06.563 Z","level":"info","msg":"Loaded system translations","caller":"i18n/i18n.go:175","for locale":"en","from locale":"/mattermost/server/i18n/en.json"}
{"timestamp":"2024-09-30 08:29:06.571 Z","level":"info","msg":"Ensuring the telemetry ID..","caller":"telemetry/telemetry.go:147"}
{"timestamp":"2024-09-30 08:29:06.572 Z","level":"info","msg":"telemetry ID is set","caller":"telemetry/telemetry.go:157","id":"yahamzkonib6fmh73rdkyasytc"}
{"timestamp":"2024-09-30 08:29:06.591 Z","level":"error","msg":"SiteURL must be set. Some features will operate incorrectly if the SiteURL is not set. See documentation for details: https://mattermost.com/pl/configure-site-url","caller":"app/server.go:390"}
{"timestamp":"2024-09-30 08:29:06.591 Z","level":"info","msg":"Current version is 10.1.0 (///)","caller":"app/server.go:404","current_version":"10.1.0","build_number":"","build_date":"","build_hash":"","build_hash_enterprise":"","service_environment":"dev"}
{"timestamp":"2024-09-30 08:29:06.591 Z","level":"info","msg":"Team Edition Build","caller":"app/server.go:420","enterprise_build":false}
{"timestamp":"2024-09-30 08:29:06.591 Z","level":"info","msg":"Printing current working","caller":"app/server.go:424","directory":"/tmp/testlib3896596472"}
{"timestamp":"2024-09-30 08:29:06.591 Z","level":"info","msg":"Loaded config","caller":"app/server.go:425","source":"memory://"}
{"timestamp":"2024-09-30 08:29:06.844 Z","level":"debug","msg":"initElasticsearchChannelIndexCheck: calling elasticsearchChannelIndexCheckWithRetry before setting up config and license change listeners...","caller":"app/elasticsearch.go:21"}
{"timestamp":"2024-09-30 08:29:06.844 Z","level":"debug","msg":"elasticsearchChannelIndexCheckWithRetry: attempting to check channel index state...","caller":"app/elasticsearch.go:64"}
{"timestamp":"2024-09-30 08:29:06.844 Z","level":"debug","msg":"elasticsearchChannelIndexCheckWithRetry: skipping because elasticsearch indexing is disabled","caller":"app/elasticsearch.go:67"}
{"timestamp":"2024-09-30 08:29:06.877 Z","level":"debug","msg":"Fetching user count for first user account check","caller":"platform/config.go:356"}
{"timestamp":"2024-09-30 08:29:06.880 Z","level":"info","msg":"Post.Message has size restrictions","caller":"sqlstore/post_store.go:2615","max_characters":16383,"max_bytes":65535}
{"timestamp":"2024-09-30 08:29:06.885 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 08:29:06.885 Z","level":"info","msg":"Starting up plugins","caller":"app/plugin.go:191"}
{"timestamp":"2024-09-30 08:29:06.885 Z","level":"debug","msg":"Enabling plugin health check job","caller":"plugin/environment.go:661","interval_s":"30s"}
{"timestamp":"2024-09-30 08:29:06.885 Z","level":"info","msg":"Syncing plugins from the file store","caller":"app/plugin.go:268"}
{"timestamp":"2024-09-30 08:29:06.885 Z","level":"debug","msg":"Plugin health check job starting.","caller":"plugin/health_check.go:31"}
{"timestamp":"2024-09-30 08:29:06.885 Z","level":"info","msg":"No plugins to sync from the file store","caller":"app/plugin.go:311"}
{"timestamp":"2024-09-30 08:29:06.886 Z","level":"debug","msg":"No prepackaged plugins directory found","caller":"app/plugin.go:912"}
{"timestamp":"2024-09-30 08:29:06.886 Z","level":"debug","msg":"Not persisting transitionally prepackaged plugins: none found","caller":"app/plugin.go:1184"}
{"timestamp":"2024-09-30 08:29:06.890 Z","level":"debug","msg":"Able to write files to local storage.","caller":"filestore/localstore.go:82"}
{"timestamp":"2024-09-30 08:29:06.909 Z","level":"info","msg":"Starting Server...","caller":"app/server.go:887"}
{"timestamp":"2024-09-30 08:29:06.909 Z","level":"info","msg":"Server is listening on 127.0.0.1:45643","caller":"app/server.go:963","address":"127.0.0.1:45643"}
{"timestamp":"2024-09-30 08:29:06.909 Z","level":"debug","msg":"No license provided; Remote Cluster services disabled","caller":"app/server.go:580"}
{"timestamp":"2024-09-30 08:29:06.975 Z","level":"debug","msg":"Initializing web routes","caller":"web/web.go:26"}
{"timestamp":"2024-09-30 08:29:06.977 Z","level":"debug","msg":"Skipping update to assets subpath since CI build","caller":"utils/subpath.go:187"}
{"timestamp":"2024-09-30 08:29:06.977 Z","level":"debug","msg":"Using client directory","caller":"web/static.go:34","clientDir":"/tmp/testlib3896596472/client"}
{"timestamp":"2024-09-30 08:29:06.978 Z","level":"debug","msg":"Configured Client4 bool string values","caller":"api4/apitestlib.go:212","true":"true","false":"False"}
{"timestamp":"2024-09-30 08:29:06.980 Z","level":"debug","msg":"Fetching user count for first user account check","caller":"platform/config.go:356"}
{"timestamp":"2024-09-30 08:29:07.841 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"kyabgwdqkbnjzydtpew57fjtnr@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:29:07.862 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"33hc89fqrid1pdmbaxt76zsmpy","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:29:07.876 Z","level":"debug","msg":"Fetching user count for first user account check","caller":"platform/config.go:356"}
{"timestamp":"2024-09-30 08:29:08.715 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"7y36dd8frinexdtx8cgr95wtxw@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:29:08.742 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"mfayny4rtffqxgdt1i8youfafc","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:29:09.583 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"9bmf9ntat3fcbj9wyxbnuxg8mh@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:29:09.600 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"qoyctggm8tgjjxjmdjr59fwsjh","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:29:10.440 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"yphnx3efxp8o8g14pfkeumdkya@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:29:10.456 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"fg33gmifoirrxjcsg3f6u8hdnc","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:29:11.295 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"9txzu9akmfrpjfmuu1gsrueh5a@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:29:11.313 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"pi1fkza54jn1ijw575p5nokb3o","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:29:12.162 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users/login","request_id":"bwrrszxwx7dm9mbq474p9zsq4w","user_id":"z1hfzzgqdjde3gm56auyqr5xyw","status_code":"200"}
{"timestamp":"2024-09-30 08:29:12.163 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users/login","request_id":"emdhg6zka7fu7rqg9umoi8he7e","user_id":"6ubadywbtbdstr61bkqp1dtmba","status_code":"200"}
{"timestamp":"2024-09-30 08:29:12.202 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 08:29:12.210 Z","level":"debug","msg":"You do not have the appropriate permissions.","caller":"web/context.go:120","path":"/api/v4/ldap/sync","request_id":"b8j36ydxjbr49n3m8xqcdq64oa","ip_addr":"127.0.0.1","user_id":"6ubadywbtbdstr61bkqp1dtmba","method":"POST","err_where":"Permissions","http_code":403,"error":"Permissions: You do not have the appropriate permissions., userId=6ubadywbtbdstr61bkqp1dtmba, permission=create_ldap_sync_job"}
{"timestamp":"2024-09-30 08:29:12.210 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/ldap/sync","request_id":"b8j36ydxjbr49n3m8xqcdq64oa","user_id":"6ubadywbtbdstr61bkqp1dtmba","status_code":"403"}
{"timestamp":"2024-09-30 08:29:12.210 Z","level":"info","msg":"Purging all caches","caller":"platform/cluster_handlers.go:114"}
{"timestamp":"2024-09-30 08:29:12.213 Z","level":"info","msg":"License key has not been uploaded. Loading license key from disk.","caller":"utils/license.go:107","filename":"/tmp/testlib3896596472/config/mattermost.mattermost-license"}
{"timestamp":"2024-09-30 08:29:12.213 Z","level":"warn","msg":"Failed to get license from disk","caller":"platform/license.go:93","error":"We could not find the license key on disk at /tmp/testlib3896596472/config/mattermost.mattermost-license: stat /tmp/testlib3896596472/config/mattermost.mattermost-license: no such file or directory"}
{"timestamp":"2024-09-30 08:29:12.214 Z","level":"warn","msg":"License key from https://mattermost.com required to unlock enterprise features.","caller":"platform/license.go:105","error":"resource \"License\" not found, id: "}
{"timestamp":"2024-09-30 08:29:12.218 Z","level":"info","msg":"Stopping Server...","caller":"app/server.go:669"}
{"timestamp":"2024-09-30 08:29:12.220 Z","level":"info","msg":"Shutting down Email batching service...","caller":"email/service.go:85"}
{"timestamp":"2024-09-30 08:29:12.220 Z","level":"info","msg":"Shutting down plugins","caller":"app/plugin.go:362"}
{"timestamp":"2024-09-30 08:29:12.220 Z","level":"debug","msg":"Disabling plugin health check job","caller":"plugin/environment.go:670"}
{"timestamp":"2024-09-30 08:29:12.220 Z","level":"info","msg":"stopping websocket hub connections","caller":"platform/web_hub.go:127"}
{"timestamp":"2024-09-30 08:29:12.221 Z","level":"info","msg":"Server stopped","caller":"app/server.go:753"}
--- FAIL: TestSyncLdap (5.74s)

Check failure on line 1 in com/mattermost/mattermost/server/v8/channels/api4

See this annotation in the file changed.

@github-actions github-actions / Postgres (Results)

com/mattermost/mattermost/server/v8/channels/api4.TestSyncLdap/SystemAdminClient#01

Failed
Raw output
=== RUN   TestSyncLdap/SystemAdminClient#01
{"timestamp":"2024-09-30 08:29:23.005 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/ldap/sync","request_id":"qmiize9bh3b87jk4yb69rsjzry","user_id":"t5ztdf55bbni5yaf9tyhwf8qpe","status_code":"200"}
==================
WARNING: DATA RACE
Read at 0x00c0016751d0 by goroutine 1200:
  reflect.maplen()
      /usr/local/go/src/runtime/map.go:1406 +0x0
  reflect.Value.lenNonSlice()
      /usr/local/go/src/reflect/value.go:1785 +0x1e9
  reflect.Value.Len()
      /usr/local/go/src/reflect/value.go:1774 +0x137
  internal/fmtsort.Sort()
      /usr/local/go/src/internal/fmtsort/sort.go:58 +0x121
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:816 +0x1144
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:853 +0x1d3e
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:853 +0x1d3e
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:921 +0x132a
  fmt.(*pp).printArg()
      /usr/local/go/src/fmt/print.go:759 +0xb84
  fmt.(*pp).doPrintf()
      /usr/local/go/src/fmt/print.go:1174 +0x10ce
  fmt.Sprintf()
      /usr/local/go/src/fmt/print.go:239 +0x5c
  github.com/stretchr/testify/mock.Arguments.Diff()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:939 +0x1b2
  github.com/stretchr/testify/mock.(*Mock).findExpectedCall()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:368 +0x147
  github.com/stretchr/testify/mock.(*Mock).MethodCalled()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:476 +0xac
  github.com/stretchr/testify/mock.(*Mock).Called()
      /go/pkg/mod/github.com/stretchr/[email protected]/mock/mock.go:466 +0x195
  github.com/mattermost/mattermost/server/v8/einterfaces/mocks.(*LdapInterface).StartSynchronizeJob()
      /mattermost/server/einterfaces/mocks/LdapInterface.go:406 +0x1b0
  github.com/mattermost/mattermost/server/v8/channels/app.(*App).SyncLdap.func1()
      /mattermost/server/channels/app/ldap.go:33 +0x1d8
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).Go.func1()
      /mattermost/server/channels/app/platform/goroutines.go:14 +0x37

Previous write at 0x00c0016751d0 by goroutine 1153:
  runtime.mapclear()
      /usr/local/go/src/runtime/map.go:989 +0x0
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).ReturnSessionToPool()
      /mattermost/server/channels/app/platform/session.go:25 +0xcf
  github.com/mattermost/mattermost/server/v8/channels/app.(*App).ReturnSessionToPool()
      /mattermost/server/channels/app/session.go:227 +0x26
  github.com/mattermost/mattermost/server/v8/channels/web.Handler.ServeHTTP.deferwrap1()
      /mattermost/server/channels/web/handlers.go:295 +0x55
  runtime.deferreturn()
      /usr/local/go/src/runtime/panic.go:602 +0x5d
  github.com/mattermost/mattermost/server/v8/channels/web.(*Handler).ServeHTTP()
      <autogenerated>:1 +0xe7
  github.com/klauspost/compress/gzhttp.NewWrapper.func1.1()
      /go/pkg/mod/github.com/klauspost/[email protected]/gzhttp/compress.go:495 +0x7c6
  net/http.HandlerFunc.ServeHTTP()
      /usr/local/go/src/net/http/server.go:2171 +0x47
  github.com/gorilla/mux.(*Router).ServeHTTP()
      /go/pkg/mod/github.com/gorilla/[email protected]/mux.go:212 +0x371
  net/http.serverHandler.ServeHTTP()
      /usr/local/go/src/net/http/server.go:3142 +0x2a1
  net/http.(*conn).serve()
      /usr/local/go/src/net/http/server.go:2044 +0x13c4
  net/http.(*Server).Serve.gowrap3()
      /usr/local/go/src/net/http/server.go:3290 +0x4f

Goroutine 1200 (running) created at:
  github.com/mattermost/mattermost/server/v8/channels/app/platform.(*PlatformService).Go()
      /mattermost/server/channels/app/platform/goroutines.go:13 +0xec
  github.com/mattermost/mattermost/server/v8/channels/app.(*Server).Go()
      /mattermost/server/channels/app/server.go:806 +0x148
  github.com/mattermost/mattermost/server/v8/channels/app.(*App).SyncLdap()
      /mattermost/server/channels/app/ldap.go:21 +0x5d
  github.com/mattermost/mattermost/server/v8/channels/api4.syncLdap()
      /mattermost/server/channels/api4/ldap.go:69 +0x9de
  github.com/mattermost/mattermost/server/v8/channels/web.Handler.ServeHTTP()
      /mattermost/server/channels/web/handlers.go:387 +0x6645
  github.com/mattermost/mattermost/server/v8/channels/web.(*Handler).ServeHTTP()
      <autogenerated>:1 +0xe7
  github.com/klauspost/compress/gzhttp.NewWrapper.func1.1()
      /go/pkg/mod/github.com/klauspost/[email protected]/gzhttp/compress.go:495 +0x7c6
  net/http.HandlerFunc.ServeHTTP()
      /usr/local/go/src/net/http/server.go:2171 +0x47
  github.com/gorilla/mux.(*Router).ServeHTTP()
      /go/pkg/mod/github.com/gorilla/[email protected]/mux.go:212 +0x371
  net/http.serverHandler.ServeHTTP()
      /usr/local/go/src/net/http/server.go:3142 +0x2a1
  net/http.(*conn).serve()
      /usr/local/go/src/net/http/server.go:2044 +0x13c4
  net/http.(*Server).Serve.gowrap3()
      /usr/local/go/src/net/http/server.go:3290 +0x4f

Goroutine 1153 (running) created at:
  net/http.(*Server).Serve()
      /usr/local/go/src/net/http/server.go:3290 +0x8ec
  github.com/mattermost/mattermost/server/v8/channels/app.(*Server).Start.func2()
      /mattermost/server/channels/app/server.go:1070 +0x224
==================
{"timestamp":"2024-09-30 08:29:23.009 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/ldap/sync","request_id":"ezkkgqeuof865b4sjrp3x8jazh","user_id":"t5ztdf55bbni5yaf9tyhwf8qpe","status_code":"200"}
    testing.go:1398: race detected during execution of test
--- FAIL: TestSyncLdap/SystemAdminClient#01 (0.01s)

Check failure on line 1 in com/mattermost/mattermost/server/v8/channels/api4

See this annotation in the file changed.

@github-actions github-actions / Postgres (Results)

com/mattermost/mattermost/server/v8/channels/api4.TestSyncLdap

Failed
Raw output
=== RUN   TestSyncLdap
{"timestamp":"2024-09-30 08:29:17.268 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 08:29:17.268 Z","level":"info","msg":"Successfully connected to cache backend","caller":"platform/service.go:191","backend":"redis","result":"PONG"}
{"timestamp":"2024-09-30 08:29:17.268 Z","level":"info","msg":"Server is initializing...","caller":"platform/service.go:194","go_version":"go1.22.6"}
{"timestamp":"2024-09-30 08:29:17.271 Z","level":"info","msg":"Starting websocket hubs","caller":"platform/web_hub.go:106","number_of_hubs":4}
{"timestamp":"2024-09-30 08:29:17.271 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":0}
{"timestamp":"2024-09-30 08:29:17.271 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":1}
{"timestamp":"2024-09-30 08:29:17.271 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":3}
{"timestamp":"2024-09-30 08:29:17.271 Z","level":"debug","msg":"Hub is starting","caller":"platform/web_hub.go:386","index":2}
{"timestamp":"2024-09-30 08:29:17.272 Z","level":"info","msg":"Loaded system translations","caller":"i18n/i18n.go:175","for locale":"en","from locale":"/mattermost/server/i18n/en.json"}
{"timestamp":"2024-09-30 08:29:17.282 Z","level":"info","msg":"Ensuring the telemetry ID..","caller":"telemetry/telemetry.go:147"}
{"timestamp":"2024-09-30 08:29:17.283 Z","level":"info","msg":"telemetry ID is set","caller":"telemetry/telemetry.go:157","id":"wj34psprojf738asks5qh678zc"}
{"timestamp":"2024-09-30 08:29:17.311 Z","level":"error","msg":"SiteURL must be set. Some features will operate incorrectly if the SiteURL is not set. See documentation for details: https://mattermost.com/pl/configure-site-url","caller":"app/server.go:390"}
{"timestamp":"2024-09-30 08:29:17.311 Z","level":"info","msg":"Current version is 10.1.0 (///)","caller":"app/server.go:404","current_version":"10.1.0","build_number":"","build_date":"","build_hash":"","build_hash_enterprise":"","service_environment":"dev"}
{"timestamp":"2024-09-30 08:29:17.311 Z","level":"info","msg":"Team Edition Build","caller":"app/server.go:420","enterprise_build":false}
{"timestamp":"2024-09-30 08:29:17.312 Z","level":"info","msg":"Printing current working","caller":"app/server.go:424","directory":"/tmp/testlib4107609806"}
{"timestamp":"2024-09-30 08:29:17.312 Z","level":"info","msg":"Loaded config","caller":"app/server.go:425","source":"memory://"}
{"timestamp":"2024-09-30 08:29:17.583 Z","level":"debug","msg":"initElasticsearchChannelIndexCheck: calling elasticsearchChannelIndexCheckWithRetry before setting up config and license change listeners...","caller":"app/elasticsearch.go:21"}
{"timestamp":"2024-09-30 08:29:17.584 Z","level":"debug","msg":"elasticsearchChannelIndexCheckWithRetry: attempting to check channel index state...","caller":"app/elasticsearch.go:64"}
{"timestamp":"2024-09-30 08:29:17.584 Z","level":"debug","msg":"elasticsearchChannelIndexCheckWithRetry: skipping because elasticsearch indexing is disabled","caller":"app/elasticsearch.go:67"}
{"timestamp":"2024-09-30 08:29:17.617 Z","level":"debug","msg":"Fetching user count for first user account check","caller":"platform/config.go:356"}
{"timestamp":"2024-09-30 08:29:17.620 Z","level":"info","msg":"Post.Message has size restrictions","caller":"sqlstore/post_store.go:2615","max_characters":16383,"max_bytes":65535}
{"timestamp":"2024-09-30 08:29:17.624 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 08:29:17.625 Z","level":"info","msg":"Starting up plugins","caller":"app/plugin.go:191"}
{"timestamp":"2024-09-30 08:29:17.625 Z","level":"debug","msg":"Enabling plugin health check job","caller":"plugin/environment.go:661","interval_s":"30s"}
{"timestamp":"2024-09-30 08:29:17.625 Z","level":"info","msg":"Syncing plugins from the file store","caller":"app/plugin.go:268"}
{"timestamp":"2024-09-30 08:29:17.625 Z","level":"info","msg":"No plugins to sync from the file store","caller":"app/plugin.go:311"}
{"timestamp":"2024-09-30 08:29:17.625 Z","level":"debug","msg":"Plugin health check job starting.","caller":"plugin/health_check.go:31"}
{"timestamp":"2024-09-30 08:29:17.625 Z","level":"debug","msg":"No prepackaged plugins directory found","caller":"app/plugin.go:912"}
{"timestamp":"2024-09-30 08:29:17.625 Z","level":"debug","msg":"Not persisting transitionally prepackaged plugins: none found","caller":"app/plugin.go:1184"}
{"timestamp":"2024-09-30 08:29:17.630 Z","level":"debug","msg":"Able to write files to local storage.","caller":"filestore/localstore.go:82"}
{"timestamp":"2024-09-30 08:29:17.648 Z","level":"info","msg":"Starting Server...","caller":"app/server.go:887"}
{"timestamp":"2024-09-30 08:29:17.649 Z","level":"info","msg":"Server is listening on 127.0.0.1:36209","caller":"app/server.go:963","address":"127.0.0.1:36209"}
{"timestamp":"2024-09-30 08:29:17.649 Z","level":"debug","msg":"No license provided; Remote Cluster services disabled","caller":"app/server.go:580"}
{"timestamp":"2024-09-30 08:29:17.714 Z","level":"debug","msg":"Initializing web routes","caller":"web/web.go:26"}
{"timestamp":"2024-09-30 08:29:17.715 Z","level":"debug","msg":"Skipping update to assets subpath since CI build","caller":"utils/subpath.go:187"}
{"timestamp":"2024-09-30 08:29:17.716 Z","level":"debug","msg":"Using client directory","caller":"web/static.go:34","clientDir":"/tmp/testlib4107609806/client"}
{"timestamp":"2024-09-30 08:29:17.716 Z","level":"debug","msg":"Configured Client4 bool string values","caller":"api4/apitestlib.go:212","true":"t","false":"false"}
{"timestamp":"2024-09-30 08:29:17.719 Z","level":"debug","msg":"Fetching user count for first user account check","caller":"platform/config.go:356"}
{"timestamp":"2024-09-30 08:29:18.562 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"txy8cgux33bgudadch1dnubabr@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:29:18.583 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"u3nejwkxk3bep89ix6jw3edi3e","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:29:18.597 Z","level":"debug","msg":"Fetching user count for first user account check","caller":"platform/config.go:356"}
{"timestamp":"2024-09-30 08:29:19.442 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"wiry43agfigtxqriz6uthd8ygw@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:29:19.461 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"bcjfhe4qttrcmc17ybyza6ozxo","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:29:20.273 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"sefekdmzxigjzmk3bk9mw993ar@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:29:20.290 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"hotec1wc5bnpdrgpf5tjtpdrbo","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:29:21.131 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"grjirenzepfn7r3t7h4o7b89xa@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:29:21.147 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"d58causo9bd9dp1q7chhrtsoto","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:29:21.984 Z","level":"debug","msg":"sending mail","caller":"mail/mail.go:295","to":"87pumcp6big3dbhpqyb55z1cew@localhost","subject":"[Mattermost] You joined "}
{"timestamp":"2024-09-30 08:29:22.001 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users","request_id":"hhzw8g6chjyd8gek6bzytjj1se","user_id":"","status_code":"201"}
{"timestamp":"2024-09-30 08:29:22.910 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users/login","request_id":"kzxbqzkuapbt5p1uhuthxc3fcy","user_id":"t5ztdf55bbni5yaf9tyhwf8qpe","status_code":"200"}
{"timestamp":"2024-09-30 08:29:22.965 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/users/login","request_id":"wndoc1ucutdqdqjw7dxytgwnwo","user_id":"atu9zh18qjfu5pk8naoohybfby","status_code":"200"}
{"timestamp":"2024-09-30 08:29:23.002 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-09-30 08:29:23.011 Z","level":"debug","msg":"You do not have the appropriate permissions.","caller":"web/context.go:120","path":"/api/v4/ldap/sync","request_id":"9c3d3sa1q3bk3exjgs17m6e94h","ip_addr":"127.0.0.1","user_id":"atu9zh18qjfu5pk8naoohybfby","method":"POST","err_where":"Permissions","http_code":403,"error":"Permissions: You do not have the appropriate permissions., userId=atu9zh18qjfu5pk8naoohybfby, permission=create_ldap_sync_job"}
{"timestamp":"2024-09-30 08:29:23.011 Z","level":"debug","msg":"Received HTTP request","caller":"web/handlers.go:185","method":"POST","url":"/api/v4/ldap/sync","request_id":"9c3d3sa1q3bk3exjgs17m6e94h","user_id":"atu9zh18qjfu5pk8naoohybfby","status_code":"403"}
{"timestamp":"2024-09-30 08:29:23.012 Z","level":"info","msg":"Purging all caches","caller":"platform/cluster_handlers.go:114"}
{"timestamp":"2024-09-30 08:29:23.014 Z","level":"info","msg":"License key has not been uploaded. Loading license key from disk.","caller":"utils/license.go:107","filename":"/tmp/testlib4107609806/config/mattermost.mattermost-license"}
{"timestamp":"2024-09-30 08:29:23.014 Z","level":"warn","msg":"Failed to get license from disk","caller":"platform/license.go:93","error":"We could not find the license key on disk at /tmp/testlib4107609806/config/mattermost.mattermost-license: stat /tmp/testlib4107609806/config/mattermost.mattermost-license: no such file or directory"}
{"timestamp":"2024-09-30 08:29:23.015 Z","level":"warn","msg":"License key from https://mattermost.com required to unlock enterprise features.","caller":"platform/license.go:105","error":"resource \"License\" not found, id: "}
{"timestamp":"2024-09-30 08:29:23.018 Z","level":"info","msg":"Stopping Server...","caller":"app/server.go:669"}
{"timestamp":"2024-09-30 08:29:23.020 Z","level":"info","msg":"Shutting down Email batching service...","caller":"email/service.go:85"}
{"timestamp":"2024-09-30 08:29:23.020 Z","level":"info","msg":"Shutting down plugins","caller":"app/plugin.go:362"}
{"timestamp":"2024-09-30 08:29:23.020 Z","level":"debug","msg":"Disabling plugin health check job","caller":"plugin/environment.go:670"}
{"timestamp":"2024-09-30 08:29:23.020 Z","level":"info","msg":"stopping websocket hub connections","caller":"platform/web_hub.go:127"}
{"timestamp":"2024-09-30 08:29:23.021 Z","level":"info","msg":"Server stopped","caller":"app/server.go:753"}
--- FAIL: TestSyncLdap (5.83s)