api.post.do_action.action_integration.app_error

[justvanbloom]

MM 5.38.1:

when i would create a meeting after join click i get:
{id: "api.post.do_action.action_integration.app_error", message: "Fehler bei Aktions-Integration.",…}
detailed_error: ""
id: "api.post.do_action.action_integration.app_error"
message: "Fehler bei Aktions-Integration."
request_id: "xxx......."
status_code: 400

[harshilsharma63]

Hi @justvanbloom ! Can you check the error in server logs? There should be a more detailed reason in there. Please set the server log level to debug, generate the error and then share the corresponding server logs. You can share the logs privately in email (link in my profile) if that's more comfortable for you.

[thomas-mc-work]

Same problem here. These are my logs exactly from that end meeting event:

{"level":"error","ts":1633073558.1786907,"caller":"mlog/log.go:251","msg":"Plugin failed to ServeHTTP, RPC call failed","plugin_id":"bigbluebutton","error":"unexpected EOF"}
{"level":"error","ts":1633073560.2258608,"caller":"mlog/log.go:251","msg":"Plugin failed to ServeHTTP, RPC call failed","plugin_id":"bigbluebutton","error":"connection is shut down"}
{"level":"error","ts":1633073565.2261412,"caller":"mlog/log.go:251","msg":"Plugin failed to ServeHTTP, muxBroker couldn't accept connection","plugin_id":"bigbluebutton","serve_http_stream_id":95,"error":"timeout waiting for accept"}
{"level":"error","ts":1633073565.2261066,"caller":"mlog/log.go:251","msg":"Plugin failed to ServeHTTP, muxBroker couldn't Accept request body connection","plugin_id":"bigbluebutton","error":"timeout waiting for accept"}
{"level":"warn","ts":1633073582.5135326,"caller":"plugin/health_check.go:59","msg":"Health check failed for plugin","id":"bigbluebutton","error":"plugin RPC connection is not responding"}
{"level":"error","ts":1633073582.5136783,"caller":"mlog/log.go:251","msg":"RPC call OnDeactivate to plugin failed.","plugin_id":"bigbluebutton","error":"connection is shut down"}
{"level":"warn","ts":1633073582.513812,"caller":"plugin/hclog_adapter.go:70","msg":"error closing client during Kill","plugin_id":"bigbluebutton","wrapped_extras":"errconnection is shut down"}
{"level":"warn","ts":1633073582.5138578,"caller":"plugin/hclog_adapter.go:72","msg":"plugin failed to exit gracefully","plugin_id":"bigbluebutton"}
{"level":"error","ts":1633073588.264944,"caller":"mlog/log.go:251","msg":"Plugin failed to ServeHTTP, RPC call failed","plugin_id":"bigbluebutton","error":"unexpected EOF"}
{"level":"error","ts":1633073603.5071197,"caller":"mlog/log.go:251","msg":"Plugin failed to ServeHTTP, RPC call failed","plugin_id":"bigbluebutton","error":"connection is shut down"}
{"level":"error","ts":1633073608.508061,"caller":"mlog/log.go:251","msg":"Plugin failed to ServeHTTP, muxBroker couldn't accept connection","plugin_id":"bigbluebutton","serve_http_stream_id":5,"error":"timeout waiting for accept"}
{"level":"error","ts":1633073608.508061,"caller":"mlog/log.go:251","msg":"Plugin failed to ServeHTTP, muxBroker couldn't Accept request body connection","plugin_id":"bigbluebutton","error":"timeout waiting for accept"}
{"level":"warn","ts":1633073612.5151148,"caller":"plugin/health_check.go:59","msg":"Health check failed for plugin","id":"bigbluebutton","error":"plugin RPC connection is not responding"}
{"level":"error","ts":1633073612.5152564,"caller":"mlog/log.go:251","msg":"RPC call OnDeactivate to plugin failed.","plugin_id":"bigbluebutton","error":"connection is shut down"}
{"level":"warn","ts":1633073612.515358,"caller":"plugin/hclog_adapter.go:70","msg":"error closing client during Kill","plugin_id":"bigbluebutton","wrapped_extras":"errconnection is shut down"}
{"level":"warn","ts":1633073612.5153937,"caller":"plugin/hclog_adapter.go:72","msg":"plugin failed to exit gracefully","plugin_id":"bigbluebutton"}

Thank you for looking into that!

[harshilsharma63]

@thomas-mc-work can you share the logs of time slightly before this? It looks like the actual error occurred before this.

[thomas-mc-work]

Alright:

{"level":"error","ts":1633073408.9649096,"caller":"mlog/log.go:251","msg":"Access to route for non-existent plugin","missing_plugin_id":"bigbluebutton","url":"/endmeeting","error":"plugin not found: bigbluebutton"}
{"level":"error","ts":1633073411.1178493,"caller":"mlog/log.go:251","msg":"Access to route for non-existent plugin","missing_plugin_id":"bigbluebutton","url":"/joinmeeting","error":"plugin not found: bigbluebutton"}
{"level":"error","ts":1633073412.5160286,"caller":"mlog/log.go:251","msg":"Access to route for non-existent plugin","missing_plugin_id":"bigbluebutton","url":"/joinmeeting","error":"plugin not found: bigbluebutton"}
{"level":"warn","ts":1633073429.6467378,"caller":"api4/config.go:356","msg":"Unrecognized config permissions tag value.","tag_value":"sysconsole_write_*_read"}
{"level":"warn","ts":1633073458.6193478,"caller":"api4/config.go:356","msg":"Unrecognized config permissions tag value.","tag_value":"sysconsole_write_*_read"}
{"level":"error","ts":1633073485.7831354,"caller":"mlog/log.go:251","msg":"RPC call OnDeactivate to plugin failed.","plugin_id":"bigbluebutton","error":"unexpected EOF"}
{"level":"warn","ts":1633073485.7831912,"caller":"plugin/hclog_adapter.go:70","msg":"error closing client during Kill","plugin_id":"bigbluebutton","wrapped_extras":"errconnection is shut down"}
{"level":"warn","ts":1633073485.7831993,"caller":"plugin/hclog_adapter.go:72","msg":"plugin failed to exit gracefully","plugin_id":"bigbluebutton"}
{"level":"info","ts":1633073524.3990788,"caller":"mlog/sugar.go:21","msg":"SUCCESS CREATE MEETINGROOM. MEETING ID: 1ytapaLsGQKsMuubceGTJK32iFc","plugin_id":"bigbluebutton"}
{"level":"info","ts":1633073524.4193902,"caller":"mlog/sugar.go:21","msg":"Successfully got meeting info","plugin_id":"bigbluebutton"}
{"level":"info","ts":1633073524.4737995,"caller":"mlog/sugar.go:21","msg":"Successfully got meeting info","plugin_id":"bigbluebutton"}
{"level":"error","ts":1633073558.1786907,"caller":"mlog/log.go:251","msg":"Plugin failed to ServeHTTP, RPC call failed","plugin_id":"bigbluebutton","error":"unexpected EOF"}

[thomas-mc-work]

ping @harshilsharma63

[harshilsharma63]

@thomas-mc-work the error Access to route for non-existent plugin meaks the plugin crashed a while back. Can you please try the latest version? Also can you please enable debug logs to see the error stacktrace?

If that doesn't work, we can quickly hop on a call and I can debug what's going on with your system.

[thomas-mc-work]

Yes, it's working now. Thank you, @harshilsharma63 !

[thomas-mc-work]

I'm sorry to say that the problems still persists :-(

Here are some log lines around the time of the occurrence. I hope this helps. If not, I'm happy to provide any support!

{"timestamp":"2021-12-21 13:43:40.577 +01:00","level":"error","msg":"Plugin failed to ServeHTTP, RPC call failed","caller":"plugin/client_rpc.go:426","plugin_id":"bigbluebutton","error":"unexpected EOF"}
{"timestamp":"2021-12-21 13:44:09.643 +01:00","level":"warn","msg":"Health check failed for plugin","caller":"plugin/health_check.go:59","id":"bigbluebutton","error":"plugin RPC connection is not responding"}
{"timestamp":"2021-12-21 13:44:09.643 +01:00","level":"error","msg":"RPC call OnDeactivate to plugin failed.","caller":"plugin/client_rpc_generated.go:33","plugin_id":"bigbluebutton","error":"connection is shut down"}
{"timestamp":"2021-12-21 13:44:09.643 +01:00","level":"warn","msg":"error closing client during Kill","caller":"plugin/hclog_adapter.go:70","plugin_id":"bigbluebutton","wrapped_extras":"errconnection is shut down"}
{"timestamp":"2021-12-21 13:44:09.643 +01:00","level":"warn","msg":"plugin failed to exit gracefully","caller":"plugin/hclog_adapter.go:72","plugin_id":"bigbluebutton"}
{"timestamp":"2021-12-21 13:44:10.663 +01:00","level":"error","msg":"Plugin failed to ServeHTTP, RPC call failed","caller":"plugin/client_rpc.go:426","plugin_id":"bigbluebutton","error":"unexpected EOF"}
{"timestamp":"2021-12-21 13:44:39.643 +01:00","level":"warn","msg":"Health check failed for plugin","caller":"plugin/health_check.go:59","id":"bigbluebutton","error":"plugin RPC connection is not responding"}
{"timestamp":"2021-12-21 13:44:39.643 +01:00","level":"error","msg":"RPC call OnDeactivate to plugin failed.","caller":"plugin/client_rpc_generated.go:33","plugin_id":"bigbluebutton","error":"connection is shut down"}
{"timestamp":"2021-12-21 13:44:39.643 +01:00","level":"warn","msg":"error closing client during Kill","caller":"plugin/hclog_adapter.go:70","plugin_id":"bigbluebutton","wrapped_extras":"errconnection is shut down"}
{"timestamp":"2021-12-21 13:44:39.643 +01:00","level":"warn","msg":"plugin failed to exit gracefully","caller":"plugin/hclog_adapter.go:72","plugin_id":"bigbluebutton"}
{"timestamp":"2021-12-21 13:45:10.748 +01:00","level":"error","msg":"Plugin failed to ServeHTTP, RPC call failed","caller":"plugin/client_rpc.go:426","plugin_id":"bigbluebutton","error":"unexpected EOF"}
{"timestamp":"2021-12-21 13:45:39.643 +01:00","level":"warn","msg":"Health check failed for plugin","caller":"plugin/health_check.go:59","id":"bigbluebutton","error":"plugin RPC connection is not responding"}
{"timestamp":"2021-12-21 13:45:39.643 +01:00","level":"error","msg":"RPC call OnDeactivate to plugin failed.","caller":"plugin/client_rpc_generated.go:33","plugin_id":"bigbluebutton","error":"connection is shut down"}
{"timestamp":"2021-12-21 13:45:39.643 +01:00","level":"warn","msg":"error closing client during Kill","caller":"plugin/hclog_adapter.go:70","plugin_id":"bigbluebutton","wrapped_extras":"errconnection is shut down"}
{"timestamp":"2021-12-21 13:45:39.643 +01:00","level":"warn","msg":"plugin failed to exit gracefully","caller":"plugin/hclog_adapter.go:72","plugin_id":"bigbluebutton"}
{"timestamp":"2021-12-21 13:47:10.834 +01:00","level":"error","msg":"Access to route for non-existent plugin","caller":"app/plugin_requests.go:37","missing_plugin_id":"bigbluebutton","url":"/plugins/bigbluebutton/meetingendedcallback?22az9QtS3jbxjDHhMOUlHDsYhc7&22az9N8NC1Q1sPRPtA9XQbzqdqS&recordingmarks=false&meetingID=22az9QtS3jbxjDHhMOUlHDsYhc7","error":"plugin not found: bigbluebutton"}
{"timestamp":"2021-12-21 13:52:10.917 +01:00","level":"error","msg":"Access to route for non-existent plugin","caller":"app/plugin_requests.go:37","missing_plugin_id":"bigbluebutton","url":"/plugins/bigbluebutton/meetingendedcallback?22az9QtS3jbxjDHhMOUlHDsYhc7&22az9N8NC1Q1sPRPtA9XQbzqdqS&recordingmarks=false&meetingID=22az9QtS3jbxjDHhMOUlHDsYhc7","error":"plugin not found: bigbluebutton"}
{"timestamp":"2021-12-21 14:00:46.243 +01:00","level":"error","msg":"Access to route for non-existent plugin","caller":"app/plugin_requests.go:37","missing_plugin_id":"bigbluebutton","url":"/joinmeeting","error":"plugin not found: bigbluebutton"}
{"timestamp":"2021-12-21 14:01:02.250 +01:00","level":"error","msg":"Access to route for non-existent plugin","caller":"app/plugin_requests.go:37","missing_plugin_id":"bigbluebutton","url":"/plugins/bigbluebutton/?id=22az9QtS3jbxjDHhMOUlHDsYhc7","error":"plugin not found: bigbluebutton"}
{"timestamp":"2021-12-21 14:01:07.126 +01:00","level":"error","msg":"Access to route for non-existent plugin","caller":"app/plugin_requests.go:37","missing_plugin_id":"bigbluebutton","url":"/endmeeting","error":"plugin not found: bigbluebutton"}

[harshilsharma63]

@thomas-mc-work would you be willing to hop on a call so I can see what's happening with the plugin? Please send me an email (address in profile) and we'll schedule one.

[thomas-mc-work]

Thank you very much for taking the time for the debugging session, Harshil! ❤️

[thomas-mc-work]

For me this has solved the problem and this issue could be closed.