polis_err_famous_proj_get2 authorUid is not defined breaks participation

laitaton commented 9 months ago

Expected behavior: Participation works and visualization is shown. Report page working normally.

Actual behavior: Participation fails to load. Browser shows error 500 and console logs error3 loading conversation model. Report page works when math calculations are finished.

To Reproduce: Still trying to reproduce it in a testing environment.

Screenshots: Memory usage from start to turning math off again. Blue line is memory usage, green is requested, meaning manually given estimation for kubernetes scheduling. There is no limit, so the redline is at 0. Memory

CPU usage seems to be fine. CPU

Additional context: We run Polis in a Kubernetes cluster in Google Cloud. The math worker is running on a node with 4 CPU and 16 GB of memory. It can use all of the node resources, other pods will be evicted to other nodes if needed. Does not seem to be out of memory error, see the screenshot of the math worker memory usage.

The error only happens when math is calculated for the conversation. That also means we can get the participation working again by removing math data from database and turning off the math worker. Of course after removing math data, report is not working. Only this conversation is influenced, others are fine.

I turn on the math worker once per day and the issue seems to persist, it occured for first time 2023-09-16.

Zid of the problematic conversation is 51.

Some logs from around the time of conversation breaking.

Math logs

DEBUG [polismath.conv-man:113] - Profile data for zid 51 :  {:meta-tids 0.007069, :zid 0.01058, :customs 475.317561, :keep-votes 0.01231, :last-vote-timestamp 130.716748, :opts' 0.014, :mod-in 0.00832, :total 606.095648, :mod-out 0.00906}
DEBUG [polismath.conv-man:359] - Message chan put in queue-message-batch! for zid: nil
INFO [polismath.conv-man:135] - Starting conversation update for zid: 5
INFO [polismath.math.conversation:784] - Starting conv-update for zid 51: N=4553, C=2481, V=469
INFO [polismath.conv-man:142] - Finished computng conv-update for zid 51 in 14 ms
INFO [polismath.components.postgres:311] - upload-math-bidtopid for zid 51
INFO [polismath.components.postgres:292] - upload-math-ptptstats for zid 51
INFO [polismath.conv-man:169] - Finished uploading math results for zid: 51

Polis server logs

info: mathpoll cache miss {"math_tick":0,"service":"polis-api-server","timestamp":"2023-09-21 07:41:54 +00:00","zid":51}
info: mathpoll cache miss {"math_tick":-1,"service":"polis-api-server","timestamp":"2023-09-21 07:41:54 +00:00","zid":51}
info: mathpoll cache miss {"math_tick":0,"service":"polis-api-server","timestamp":"2023-09-21 07:41:54 +00:00","zid":51}
info: after cache miss, found item, adding to cache {"math_tick":0,"service":"polis-api-server","timestamp":"2023-09-21 07:41:54 +00:00","zid":51}
info: after cache miss, found item, adding to cache {"math_tick":-1,"service":"polis-api-server","timestamp":"2023-09-21 07:41:54 +00:00","zid":51}
info: after cache miss, found item, adding to cache {"math_tick":0,"service":"polis-api-server","timestamp":"2023-09-21 07:41:54 +00:00","zid":51}
info: math from cache {"math_tick":-1,"service":"polis-api-server","timestamp":"2023-09-21 07:41:54 +00:00","zid":51}
info: math was cached but not new {"cached_math_tick":4,"query_math_tick":4,"service":"polis-api-server","timestamp":"2023-09-21 07:41:57 +00:00","zid":51}
GET /api/v3/group_demographics?conversation_id=8rkeeeszdd&report_id=r5ecrwjxcjvdtm7xtrtma 200 211.439 ms - 2
error: polis_err_famous_proj_get2 authorUid is not defined {"service":"polis-api-server","stack":"ReferenceError: authorUid is not defined
    at /app/dist/src/server.js:8217:39
    at Array.map (<anonymous>)
    at getSocialParticipants (/app/dist/src/server.js:8211:52)
    at /app/dist/src/server.js:9060:17
    at tryCatcher (/app/node_modules/bluebird/js/release/util.js:16:23)
    at Promise._settlePromiseFromHandler (/app/node_modules/bluebird/js/release/promise.js:517:31)
    at Promise._settlePromise (/app/node_modules/bluebird/js/release/promise.js:574:18)
    at Promise._settlePromise0 (/app/node_modules/bluebird/js/release/promise.js:619:10)
    at Promise._settlePromises (/app/node_modules/bluebird/js/release/promise.js:699:18)
    at Promise._fulfill (/app/node_modules/bluebird/js/release/promise.js:643:18)
    at PromiseArray._resolve (/app/node_modules/bluebird/js/release/promise_array.js:126:19)
    at PromiseArray._promiseFulfilled (/app/node_modules/bluebird/js/release/promise_array.js:144:14)
    at Promise._settlePromise (/app/node_modules/bluebird/js/release/promise.js:579:26)
    at Promise._settlePromise0 (/app/node_modules/bluebird/js/release/promise.js:619:10)
    at Promise._settlePromises (/app/node_modules/bluebird/js/release/promise.js:699:18)
    at _drainQueueStep (/app/node_modules/bluebird/js/release/async.js:138:12)
    at _drainQueue (/app/node_modules/bluebird/js/release/async.js:131:9)
    at Async._drainQueues (/app/node_modules/bluebird/js/release/async.js:147:5)
    at Async.drainQueues [as _onImmediate] (/app/node_modules/bluebird/js/release/async.js:17:14)
    at process.processImmediate (node:internal/timers:476:21)
    at process.topLevelDomainCallback (node:domain:161:15)
    at process.callbackTrampoline (node:internal/async_hooks:128:24)","timestamp":"2023-09-21 07:41:59 +00:00"}
GET /api/v3/votes/famous?conversation_id=8rkeeeszdd&math_tick=5&xid=41b37aa0-526a-4f4f-8b10-7072c9e46dc9 500 7.204 ms - -
error: polis_err_famous_proj_get2 authorUid is not defined {"service":"polis-api-server","stack":"ReferenceError: authorUid is not defined
    at /app/dist/src/server.js:8217:39
    at Array.map (<anonymous>)
    at getSocialParticipants (/app/dist/src/server.js:8211:52)
    at /app/dist/src/server.js:9060:17
    at tryCatcher (/app/node_modules/bluebird/js/release/util.js:16:23)
    at Promise._settlePromiseFromHandler (/app/node_modules/bluebird/js/release/promise.js:517:31)
    at Promise._settlePromise (/app/node_modules/bluebird/js/release/promise.js:574:18)
    at Promise._settlePromise0 (/app/node_modules/bluebird/js/release/promise.js:619:10)
    at Promise._settlePromises (/app/node_modules/bluebird/js/release/promise.js:699:18)
    at Promise._fulfill (/app/node_modules/bluebird/js/release/promise.js:643:18)
    at PromiseArray._resolve (/app/node_modules/bluebird/js/release/promise_array.js:126:19)
    at PromiseArray._promiseFulfilled (/app/node_modules/bluebird/js/release/promise_array.js:144:14)
    at Promise._settlePromise (/app/node_modules/bluebird/js/release/promise.js:579:26)
    at Promise._settlePromise0 (/app/node_modules/bluebird/js/release/promise.js:619:10)
    at Promise._settlePromises (/app/node_modules/bluebird/js/release/promise.js:699:18)
    at _drainQueueStep (/app/node_modules/bluebird/js/release/async.js:138:12)
    at _drainQueue (/app/node_modules/bluebird/js/release/async.js:131:9)
    at Async._drainQueues (/app/node_modules/bluebird/js/release/async.js:147:5)
    at Async.drainQueues [as _onImmediate] (/app/node_modules/bluebird/js/release/async.js:17:14)
    at process.processImmediate (node:internal/timers:476:21)
    at process.topLevelDomainCallback (node:domain:161:15)
    at process.callbackTrampoline (node:internal/async_hooks:128:24)","timestamp":"2023-09-21 07:42:00 +00:00"}
GET /api/v3/votes/famous?conversation_id=8rkeeeszdd&math_tick=5 500 248.726 ms - -
warn: getXidRecordByXidOwnerId: no xInfo yet {"service":"polis-api-server","timestamp":"2023-09-21 07:42:00 +00:00"}

metasoarous commented 9 months ago

Hi @laitaton. Thanks for sharing this issue here.

I took the liberty of reformatting the logs a bit to make them easier to read.

It looks to me like the math worker isn't actually the problem, since the math updates are succeeding without issue. Moreover, the server logs suggest that it's the /api/v3/votes/famous request that is erroring out with polis_err_famous_proj_get2 authorUid is not defined.

A similar issue was resolved in a PR merged in Feb 18th of this year: https://github.com/compdemocracy/polis/issues/1508

What commit are you running on?

Suggestions:

If you're using an older commit, please update
If that doesn't work, as a stopgap, you could disable the visualization, since this may keep the conversation from having to hit that request. Right now, leaving the math worker off kills the visualization anyway, but you're not getting the benefit of comment routing, which is ultimately more important for the data collected.

Thanks again

laitaton commented 9 months ago

Thank you @metasoarous for the help! The PR did help and now the conversation is running with math worker and data normally.

We're using commit: https://github.com/compdemocracy/polis/tree/5d031eda5362ab560f97e1ca49945af44186162a I tried first updating to latest edge, but was not able to overcome report page JS and CSS 404 errors. So I continue to use same commit as before, and made a patch file for this small change in server.ts: "authorUid"->"authoruid".

compdemocracy / polis