[Bug]: Telemetry Server - race condition causes fatal error

[jaredholloway94]

✈ Pre-Flight checks

• I don't have SentinelOne antivirus installed (see above for the solution)
• I have searched in the issues (open and closed) but couldn't find a similar issue
• I have searched in the pyRevit Forum for similar issues
• I already followed the installation troubleshooting guide thoroughly
• I am using the latest pyRevit Version

🐞 Describe the bug

Telemetry server crashes with error "fatal error: concurrent map writes" or "fatal error: concurrent map read and write". The server process has to be manually restarted following this failure, which is problematic for a reporting tool that is designed to run unattended.

It seems to be caused by a race condition accessing some map in the Golang code. I don't know Go well enough to trace the error back to the offending function(s).

A quick google says this can be resolved by using sync.Map instead of Map, to tell Go to manage concurrent access internally.

⌨ Error/Debug Message

fatal error: concurrent map writes

goroutine 4513 [running]:
pyrevittelemetryserver/persistence.EventTelemetryRecordV2.Validate({{{0xc00037a190, 0x3}}, {0xc0000aa0c0, 0x1e}, {0xc000332000, 0x24}, {0xc00038c030, 0x12}, 0xc000546360, {0xc00037a160, ...}, ...})
        D:/a/pyRevit/pyRevit/dev/pyRevitTelemetryServer/persistence/models.go:202 +0x2d
pyrevittelemetryserver/server.RouteEvents.func1({0x7ff7da17ee90, 0xc000774000}, 0xc00007e400)
        D:/a/pyRevit/pyRevit/dev/pyRevitTelemetryServer/server/events.go:47 +0x178
net/http.HandlerFunc.ServeHTTP(0xc00007e200?, {0x7ff7da17ee90?, 0xc000774000?}, 0x1?)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:2141 +0x29
github.com/gorilla/mux.(*Router).ServeHTTP(0xc00051a000, {0x7ff7da17ee90, 0xc000774000}, 0xc00007e000)
        C:/Users/runneradmin/go/pkg/mod/github.com/gorilla/mux@v1.8.0/mux.go:210 +0x1c5
net/http.serverHandler.ServeHTTP({0x7ff7da17d850?}, {0x7ff7da17ee90?, 0xc000774000?}, 0x6?)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:2943 +0x8e
net/http.(*conn).serve(0xc000322090, {0x7ff7da17f7e8, 0xc000029170})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:2014 +0x5f4
created by net/http.(*Server).Serve in goroutine 1
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:3091 +0x5cb

goroutine 1 [IO wait]:
internal/poll.runtime_pollWait(0x226f9c54fa0, 0x72)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/runtime/netpoll.go:343 +0x85
internal/poll.(*pollDesc).wait(0x0?, 0x0?, 0x0)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.execIO(0xc00032bb98, 0xc0000e7990)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/internal/poll/fd_windows.go:175 +0xe6
internal/poll.(*FD).acceptOne(0xc00032bb80, 0x4a8, {0xc0000ac000?, 0x29?, 0xc0000e7a38?}, 0x7ff7d98ba2f7?)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/internal/poll/fd_windows.go:944 +0x67
internal/poll.(*FD).Accept(0xc00032bb80, 0xc0000e7b68)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/internal/poll/fd_windows.go:978 +0x1bc
net.(*netFD).accept(0xc00032bb80)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/fd_windows.go:166 +0x54
net.(*TCPListener).accept(0xc000165360)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/tcpsock_posix.go:152 +0x1e
net.(*TCPListener).Accept(0xc000165360)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/tcpsock.go:315 +0x30
net/http.(*Server).Serve(0xc000176d20, {0x7ff7da17f010, 0xc000165360})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:3061 +0x364
net/http.(*Server).ListenAndServe(0xc000176d20)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:2990 +0x71
net/http.ListenAndServe(...)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:3244
pyrevittelemetryserver/server.Start(0xc0003269a0, {0x7ff7da1801e8, 0xc000462a80}, 0x2?)
        D:/a/pyRevit/pyRevit/dev/pyRevitTelemetryServer/server/server.go:50 +0x485
main.main()
        D:/a/pyRevit/pyRevit/dev/pyRevitTelemetryServer/main.go:35 +0x25b

goroutine 4065 [select]:
net.(*Resolver).lookupIPAddr(0x7ff7da5e9760, {0x7ff7da17f628?, 0x7ff7da63f720}, {0x7ff7da03983a, 0x3}, {0xc00065a450, 0x9})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/lookup.go:332 +0x3fe
net.(*Resolver).internetAddrList(0x7ff7da17f628?, {0x7ff7da17f628?, 0x7ff7da63f720?}, {0x7ff7da03983a, 0x3}, {0xc00065a450?, 0xc0000dae40?})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/ipsock.go:288 +0x4e5
net.(*Resolver).resolveAddrList(0x7ff7da63f720?, {0x7ff7da17f628, 0x7ff7da63f720}, {0x7ff7da03a54b, 0x4}, {0x7ff7da03983a?, 0x0?}, {0xc00065a450, 0xe}, {0x0, ...})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/dial.go:282 +0x405
net.(*Dialer).DialContext(0xc0000db038, {0x7ff7da17f628, 0x7ff7da63f720}, {0x7ff7da03983a, 0x3}, {0xc00065a450, 0xe})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/dial.go:488 +0x42c
github.com/lib/pq.defaultDialer.DialContext(...)
        C:/Users/runneradmin/go/pkg/mod/github.com/lib/pq@v1.10.3/conn.go:119
github.com/lib/pq.dial({0x7ff7da17f628, 0x7ff7da63f720}, {0x7ff7da17d5f0, 0xc000326700}, 0xc0000ae6c0?)
        C:/Users/runneradmin/go/pkg/mod/github.com/lib/pq@v1.10.3/conn.go:385 +0x3bd
github.com/lib/pq.(*Connector).open(0xc000008498, {0x7ff7da17f628, 0x7ff7da63f720})
        C:/Users/runneradmin/go/pkg/mod/github.com/lib/pq@v1.10.3/conn.go:322 +0x285
github.com/lib/pq.DialOpen({0x7ff7da17d5f0?, 0xc000326700}, {0xc00007c0c0?, 0x7ff7da601980?})
        C:/Users/runneradmin/go/pkg/mod/github.com/lib/pq@v1.10.3/conn.go:291 +0x7b
github.com/lib/pq.Open(...)
        C:/Users/runneradmin/go/pkg/mod/github.com/lib/pq@v1.10.3/conn.go:281
github.com/lib/pq.Driver.Open({}, {0xc00007c0c0, 0x57})
        C:/Users/runneradmin/go/pkg/mod/github.com/lib/pq@v1.10.3/conn.go:54 +0x85
database/sql.dsnConnector.Connect(...)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/database/sql/sql.go:758
database/sql.(*DB).conn(0xc0003a20d0, {0x7ff7da17f628, 0x7ff7da63f720}, 0x1)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/database/sql/sql.go:1387 +0x717
database/sql.(*DB).begin(0x7ff7da63f720?, {0x7ff7da17f628, 0x7ff7da63f720}, 0x10?, 0xa0?)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/database/sql/sql.go:1853 +0x2d
database/sql.(*DB).BeginTx.func1(0x57?)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/database/sql/sql.go:1836 +0x3e
database/sql.(*DB).retry(0x1?, 0xc0000db6d0)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/database/sql/sql.go:1538 +0x42
database/sql.(*DB).BeginTx(0x7ff7da03bdd3?, {0x7ff7da17f628?, 0x7ff7da63f720?}, 0x57?)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/database/sql/sql.go:1835 +0x85
database/sql.(*DB).Begin(...)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/database/sql/sql.go:1849
pyrevittelemetryserver/persistence.commitSQL({0x7ff7da03bdd3?, 0x6?}, {0xc00007c0c0?, 0x1?}, {0xc000380000, 0x296}, 0xc0000db860?)
        D:/a/pyRevit/pyRevit/dev/pyRevitTelemetryServer/persistence/genericsql.go:100 +0x10c
pyrevittelemetryserver/persistence.GenericSQLConnection.WriteEventTelemetryV2({{0xc00065a130?}}, 0x3?, 0xc00001e1c0?)
        D:/a/pyRevit/pyRevit/dev/pyRevitTelemetryServer/persistence/genericsql.go:86 +0xad
pyrevittelemetryserver/server.RouteEvents.func1({0x7ff7da17ee90, 0xc0000bc000}, 0xc0000ea100)
        D:/a/pyRevit/pyRevit/dev/pyRevitTelemetryServer/server/events.go:56 +0x29d
net/http.HandlerFunc.ServeHTTP(0xc0000ea000?, {0x7ff7da17ee90?, 0xc0000bc000?}, 0x1?)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:2141 +0x29
github.com/gorilla/mux.(*Router).ServeHTTP(0xc00051a000, {0x7ff7da17ee90, 0xc0000bc000}, 0xc00007e100)
        C:/Users/runneradmin/go/pkg/mod/github.com/gorilla/mux@v1.8.0/mux.go:210 +0x1c5
net/http.serverHandler.ServeHTTP({0x7ff7da17d850?}, {0x7ff7da17ee90?, 0xc0000bc000?}, 0x6?)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:2943 +0x8e
net/http.(*conn).serve(0xc0000a0000, {0x7ff7da17f7e8, 0xc000029170})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:2014 +0x5f4
created by net/http.(*Server).Serve in goroutine 1
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:3091 +0x5cb

goroutine 4547 [select]:
database/sql.(*DB).connectionOpener(0xc0003a20d0, {0x7ff7da17f820, 0xc0000b20f0})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/database/sql/sql.go:1218 +0x87
created by database/sql.OpenDB in goroutine 4065
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/database/sql/sql.go:791 +0x165

goroutine 4530 [IO wait]:
internal/poll.runtime_pollWait(0x226f9c54ac8, 0x72)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/runtime/netpoll.go:343 +0x85
internal/poll.(*pollDesc).wait(0x3e3?, 0xc00072be60?, 0x0)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.execIO(0xc00035e018, 0x7ff7da0868f0)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/internal/poll/fd_windows.go:175 +0xe6
internal/poll.(*FD).Read(0xc00035e000, {0xc0005460a1, 0x1, 0x1})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/internal/poll/fd_windows.go:436 +0x2b1
net.(*netFD).Read(0xc00035e000, {0xc0005460a1?, 0xc00072bf40?, 0x7ff7d98b7e90?})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/fd_posix.go:55 +0x25
net.(*conn).Read(0xc000066010, {0xc0005460a1?, 0xc00072bf01?, 0xc00073e050?})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/net.go:185 +0x45
net/http.(*connReader).backgroundRead(0xc000546090)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:683 +0x37
created by net/http.(*connReader).startBackgroundRead in goroutine 4513
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:679 +0xba

goroutine 4548 [runnable]:
net.(*Resolver).lookupIP(0x18?, {0x7ff7da17f820, 0xc0000b2140}, {0x7ff7da03983a, 0x3}, {0xc00065a450, 0x9})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/lookup_windows.go:182 +0x21a
net.glob..func1({0x7ff7da17f820?, 0xc0000b2140?}, 0xc000038f00?, {0x7ff7da03983a?, 0x7ff7d985ae88?}, {0xc00065a450?, 0xc000761f38?})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/hook.go:23 +0x37
net.(*Resolver).lookupIPAddr.func1()
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/lookup.go:324 +0x3a
internal/singleflight.(*Group).doCall(0x7ff7da5e9770, 0xc0000b2190, {0xc00065a460, 0xd}, 0xc0005fe600?)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/internal/singleflight/singleflight.go:93 +0x35
created by internal/singleflight.(*Group).DoChan in goroutine 4065
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/internal/singleflight/singleflight.go:86 +0x2e9

goroutine 4546 [IO wait]:
internal/poll.runtime_pollWait(0x226f9c549d0, 0x72)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/runtime/netpoll.go:343 +0x85
internal/poll.(*pollDesc).wait(0x3e3?, 0xc0003f7e60?, 0x0)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.execIO(0xc00045e018, 0x7ff7da0868f0)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/internal/poll/fd_windows.go:175 +0xe6
internal/poll.(*FD).Read(0xc00045e000, {0xc000546131, 0x1, 0x1})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/internal/poll/fd_windows.go:436 +0x2b1
net.(*netFD).Read(0xc00045e000, {0xc000546131?, 0xc0003f7f40?, 0xc0003f7f98?})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/fd_posix.go:55 +0x25
net.(*conn).Read(0xc0000b0000, {0xc000546131?, 0xc000604ea0?, 0x0?})
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/net.go:185 +0x45
net/http.(*connReader).backgroundRead(0xc000546120)
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:683 +0x37
created by net/http.(*connReader).startBackgroundRead in goroutine 4065
        C:/hostedtoolcache/windows/go/1.21.13/x64/src/net/http/server.go:679 +0xba

♻️ To Reproduce

No response

⏲️ Expected behavior

No response

🖥️ Hardware and Software Setup (please complete the following information)

==> Registered Clones (full git repos)
==> Registered Clones (deployed from archive/image)
master | Deploy: "basepublic" | Branch: "master" | Version: "4.8.16.24121+2117" | Path: "C:\Users\jholloway\AppData\Roaming\pyRevit-Master"
==> Attachments
Unnamed-363FBF8 | Product: "Autodesk Revit 2025" | Engine: DEFAULT (2711) | Path: "C:\Program Files\pyRevit-Master" | AllUsers
Unnamed-363FBF8 | Product: "Autodesk Revit 2024" | Engine: DEFAULT (2711) | Path: "C:\Program Files\pyRevit-Master" | AllUsers
Unnamed-363FBF8 | Product: "Autodesk Revit 2023" | Engine: DEFAULT (2711) | Path: "C:\Program Files\pyRevit-Master" | AllUsers
Unnamed-363FBF8 | Product: "Autodesk Revit 2022" | Engine: DEFAULT (2711) | Path: "C:\Program Files\pyRevit-Master" | AllUsers
Unnamed-363FBF8 | Product: "2021.1.8" | Engine: DEFAULT (2711) | Path: "C:\Program Files\pyRevit-Master" | AllUsers
Unnamed-363FBF8 | Product: "2019.2.6" | Engine: DEFAULT (2711) | Path: "C:\Program Files\pyRevit-Master" | AllUsers
==> Installed Extensions
pyBimManager | Type: Unknown | Repo: "" | Installed: "S:\Office\BIM\Revit\pyRevit\pyBimManager\pyBimManager.lib"
pyBimManager-Admin | Type: Unknown | Repo: "" | Installed: "S:\Office\BIM\Revit\pyRevit\pyBimManager\pyBimManager-Admin.extension"
pyBimManager-User | Type: Unknown | Repo: "" | Installed: "S:\Office\BIM\Revit\pyRevit\pyBimManager\pyBimManager-User.extension"
==> Default Extension Search Path
C:\Users\jholloway\AppData\Roaming\pyRevit\Extensions
==> Extension Search Paths
S:\Office\BIM\Revit\pyRevit\pyBimManager
==> Extension Sources - Default
https://github.com/eirannejad/pyRevit/raw/master/extensions/extensions.json
==> Extension Sources - Additional
==> Installed Revits
Autodesk Revit 2025 | Version: 25.4.0.32 | Build: 20241202_1040(x64) | Language: 1033 | Path: "C:\Program Files\Autodesk\Revit 2025\"
Autodesk Revit 2024 | Version: 24.3.10.22 | Build: 20241105_1515(x64) | Language: 1033 | Path: "C:\Program Files\Autodesk\Revit 2024\"
Autodesk Revit 2023 | Version: 23.1.60.36 | Build: 20241107_1515(x64) | Language: 1033 | Path: "C:\Program Files\Autodesk\Revit 2023\"
Autodesk Revit 2022 | Version: 22.1.80.32 | Build: 20241107_1515(x64) | Language: 1033 | Path: "C:\Program Files\Autodesk\Revit 2022\"
2021.1.8 | Version: 21.1.80.35 | Build: 20230515_1515(x64) | Language: 1033 | Path: "C:\Program Files\Autodesk\Revit 2021\"
2019.2.6 | Version: 19.2.60.3 | Build: 20220224_1700(x64) | Language: 1033 | Path: "C:\Program Files\Autodesk\Revit 2019\"
==> Running Revit Instances
Error: Object reference not set to an instance of an object.

Additional context

No response

[jaredholloway94]

As a temporary workaround, while I'm trying to fix the Go code, I'm running this in an infinite while loop:

while ($true) {
    write-host "`n`n`n`n"
    write-host "SERVER RESTARTED"
    write-host "`n`n`n`n"
    pyRevit-TelemetryServer ...
}

If the fatal error causes it to break out of this loop, I'll report back.
Since I can't force the error, I'll just have to wait.

[jmcouffin]

any news?

[jaredholloway94]

I moved the telemetry server to a docker container (https://github.com/jaredholloway94/docker-pyRevitTelemetry) to monitor and restart more easily, but have not done any more to fix the Go code. Planning to get back to this next week.

[jmcouffin]

bump @jaredholloway94 😜

[jaredholloway94]

@jmcouffin see PR #2646