search

crossbario / crossbar

Crossbar.io - WAMP application router
https://crossbar.io/
Other
2.05k stars 274 forks source link

Master doesn't start with the new release #1951

Closed om26er closed 2 years ago

om26er commented 2 years ago

Cannot start crossbar master on the latest release version of crossbar

(venv) om26er@HomePC:~/Documents/master$ crossbar master start

2022-02-25T02:11:57+0500 [Controller 1054974] 
2022-02-25T02:11:57+0500 [Controller 1054974]     :::::::::::::::::
2022-02-25T02:11:57+0500 [Controller 1054974]           :::::          _____                 __              _____  __
2022-02-25T02:11:57+0500 [Controller 1054974]     :::::   :   :::::   / ___/______  ___ ___ / /  ___ _____  / __/ |/_/
2022-02-25T02:11:57+0500 [Controller 1054974]     :::::::   :::::::  / /__/ __/ _ \(_-<(_-</ _ \/ _ `/ __/ / _/_>  <
2022-02-25T02:11:57+0500 [Controller 1054974]     :::::   :   :::::  \___/_/  \___/___/___/_.__/\_,_/_/   /_/ /_/|_|
2022-02-25T02:11:57+0500 [Controller 1054974]           :::::
2022-02-25T02:11:57+0500 [Controller 1054974]     :::::::::::::::::   Crossbar.io FX v22.2.1 [19000101-0000000]
2022-02-25T02:11:57+0500 [Controller 1054974] 
2022-02-25T02:11:57+0500 [Controller 1054974]     Copyright (c) 2013-2022 Crossbar.io Technologies GmbH. All rights reserved.
2022-02-25T02:11:57+0500 [Controller 1054974] 
2022-02-25T02:11:57+0500 [Controller 1054974] Booting master node .. <crossbar.node.main._run_command_start>
2022-02-25T02:11:57+0500 [Controller 1054974] Node configuration loaded [config_source=default, config_path=/home/om26er/Documents/venv/lib/python3.8/site-packages/crossbar/master/node/config.json]
2022-02-25T02:11:57+0500 [Controller 1054974] New node key pair generated! Public key is 0x4a909a0511fd1ec41f33ee0e4c5fe723ce77de9ca201809e0148f54462c14244
2022-02-25T02:11:57+0500 [Controller 1054974] File permissions on node public key fixed
2022-02-25T02:11:57+0500 [Controller 1054974] File permissions on node private key fixed
2022-02-25T02:11:57+0500 [Controller 1054974] Node key loaded from /home/om26er/Documents/master/key.priv
2022-02-25T02:11:57+0500 [Controller 1054974] Entering event reactor ...
2022-02-25T02:11:57+0500 [Controller 1054974] Starting node (initialize master-node personality) .. [<crossbar.master.node.node.FabricCenterNode.start>]
2022-02-25T02:11:57+0500 [Controller 1054974] Starting node (initialize edge-node personality) .. [<crossbar.edge.node.node.FabricNode.start>]
2022-02-25T02:11:57+0500 [Controller 1054974] Starting node .. [<crossbar.node.node.Node.start>]
2022-02-25T02:11:57+0500 [Controller 1054974] Node ID center1 set from explicit configuration
2022-02-25T02:11:57+0500 [Controller 1054974] RouterFactory.start_realm: router created for realm "crossbar"
2022-02-25T02:11:57+0500 [Controller 1054974] <crossbar.node.node.Node._add_global_roles> node-wide role "controller" added on node management router realm "crossbar"
2022-02-25T02:11:57+0500 [Controller 1054974] attached session 5880828933304118 to realm "crossbar" (authid="serviceagent", authrole="trusted") <crossbar.router.router.Router.attach>
2022-02-25T02:11:57+0500 [Controller 1054974] <crossbar.router.service.RouterServiceAgent.onJoin>: realm service session attached to realm "crossbar" [session_id=5880828933304118, authid="serviceagent", authrole="trusted", on_ready=None]
2022-02-25T02:11:57+0500 [Controller 1054974] <crossbar.master.node.node.FabricCenterNode.start> router service agent session attached [<crossbar.router.service.RouterServiceAgent>]
2022-02-25T02:11:57+0500 [Controller 1054974] Docker daemon integration disabled!
2022-02-25T02:11:57+0500 [Controller 1054974] attached session 7901654166514505 to realm "crossbar" (authid="nodecontroller", authrole="controller") <crossbar.router.router.Router.attach>
2022-02-25T02:11:57+0500 [Controller 1054974] <crossbar.node.controller.NodeController.onJoin>: joined realm="crossbar" on local node management router [authid="nodecontroller", authrole="controller"]
2022-02-25T02:11:57+0500 [Controller 1054974] Signal handler installed on process 1054974 thread 139873868998464
2022-02-25T02:11:57+0500 [Controller 1054974] <crossbar.master.node.node.FabricCenterNode.start> node controller session attached [<crossbar.edge.node.node.FabricNodeControllerSession>]
2022-02-25T02:11:57+0500 [Controller 1054974] <crossbar.master.node.node.FabricCenterNode.boot>::NODE_BOOT_BEGIN
2022-02-25T02:11:57+0500 [Controller 1054974] Booting node <crossbar.master.node.node.FabricCenterNode.boot>
2022-02-25T02:11:57+0500 [Controller 1054974] Booting node from local configuration [parallel_worker_start=False] .. <crossbar.node.node.Node.boot_from_config>
2022-02-25T02:11:57+0500 [Controller 1054974] Will start 2 workers ..
2022-02-25T02:11:57+0500 [Controller 1054974] Order node to start "Router cfrouter1" ..
2022-02-25T02:11:57+0500 [Controller 1054974] Starting router-worker "cfrouter1" .. <crossbar.node.controller.NodeController.start_worker>
2022-02-25T02:11:57+0500 [Controller 1054974] worker-specific role "crossbar.worker.cfrouter1" added on node management router realm "crossbar" <crossbar.master.node.node.FabricCenterNode._add_worker_role>

2022-02-25T02:11:58+0500 [Router     1055011] Starting router-worker "cfrouter1" on node "center1" (personality "master") and local node management realm "crossbar" .. <crossbar.edge.worker.router.ExtRouterController>
2022-02-25T02:11:58+0500 [Router     1055011] Running as PID 1055011 on CPython-EPollReactor
2022-02-25T02:11:58+0500 [Router     1055011] Entering event reactor ...
2022-02-25T02:11:58+0500 [Controller 1054974] attached session 4934916645490666 to realm "crossbar" (authid="crossbar.process.1055011", authrole="crossbar.worker.cfrouter1") <crossbar.router.router.Router.attach>
2022-02-25T02:11:58+0500 [Router     1055011] Router worker session for "cfrouter1" joined realm "crossbar" on node router <crossbar.worker.router.RouterController.onJoin>
2022-02-25T02:11:58+0500 [Router     1055011] Router worker session for "cfrouter1" ready
2022-02-25T02:11:58+0500 [Controller 1054974] Ok, node has started Router cfrouter1
2022-02-25T02:11:58+0500 [Controller 1054974] Configuring Router cfrouter1 ..
2022-02-25T02:11:58+0500 [Controller 1054974] Order Router cfrouter1 to start Realm realm001
2022-02-25T02:11:58+0500 [Router     1055011] Starting router realm "realm001" <crossbar.edge.worker.router.ExtRouterController.start_router_realm>
2022-02-25T02:11:58+0500 [Router     1055011] Starting router realm realm001 <crossbar.worker.router.RouterController.start_router_realm>
2022-02-25T02:11:58+0500 [Router     1055011] RouterFactory.start_realm: router created for realm "com.crossbario.fabric"
2022-02-25T02:11:58+0500 [Router     1055011] attached session 8719448093671515 to realm "com.crossbario.fabric" (authid="routerworker-cfrouter1-realm-realm001-serviceagent", authrole="trusted") <crossbar.router.router.Router.attach>
2022-02-25T02:11:58+0500 [Router     1055011] <crossbar.router.service.RouterServiceAgent.onJoin>: realm service session attached to realm "com.crossbario.fabric" [session_id=8719448093671515, authid="routerworker-cfrouter1-realm-realm001-serviceagent", authrole="trusted", on_ready=<Deferred at 0x7f2bfa9764c0>]
2022-02-25T02:11:58+0500 [Router     1055011] <crossbar.worker.router.RouterController.set_service_session>(session=<crossbar.router.service.RouterServiceAgent object at 0x7f2bfa8ce610>, realm="com.crossbario.fabric", authrole="trusted")
2022-02-25T02:11:58+0500 [Router     1055011] RouterServiceAgent started on realm="com.crossbario.fabric" with authrole="trusted", authid="routerworker-cfrouter1-realm-realm001-serviceagent"
2022-02-25T02:11:58+0500 [Router     1055011] Realm "realm001" (name="com.crossbario.fabric", authrole="trusted", authid="routerworker-cfrouter1-realm-realm001-serviceagent") started
2022-02-25T02:11:58+0500 [Controller 1054974] Ok, Router cfrouter1 has started Realm realm001
2022-02-25T02:11:58+0500 [Controller 1054974] Order Realm realm001 to start Role role001
2022-02-25T02:11:58+0500 [Router     1055011] Role role001 named "public" started on realm "com.crossbario.fabric"
2022-02-25T02:11:58+0500 [Controller 1054974] Ok, Realm realm001 has started Role role001
2022-02-25T02:11:58+0500 [Controller 1054974] Order Realm realm001 to start Role role002
2022-02-25T02:11:58+0500 [Router     1055011] Role role002 named "user" started on realm "com.crossbario.fabric"
2022-02-25T02:11:58+0500 [Controller 1054974] Ok, Realm realm001 has started Role role002
2022-02-25T02:11:58+0500 [Controller 1054974] Order Realm realm001 to start Role role003
2022-02-25T02:11:58+0500 [Router     1055011] Role role003 named "user-backend" started on realm "com.crossbario.fabric"
2022-02-25T02:11:58+0500 [Controller 1054974] Ok, Realm realm001 has started Role role003
2022-02-25T02:11:58+0500 [Controller 1054974] Order Realm realm001 to start Role role004
2022-02-25T02:11:58+0500 [Router     1055011] Role role004 named "authenticator" started on realm "com.crossbario.fabric"
2022-02-25T02:11:58+0500 [Controller 1054974] Ok, Realm realm001 has started Role role004
2022-02-25T02:11:58+0500 [Router     1055011] attached session 3036875065702237 to realm "com.crossbario.fabric" (authid="4fd75eb9-380c-4d23-a665-f690a314f8cd", authrole="authenticator") <crossbar.router.router.Router.attach>
2022-02-25T02:11:58+0500 [Router     1055011] started component: crossbar.master.node.authenticator.Authenticator id=3036875065702237
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 001 for database table <ae2fe53f-f8ec-4484-8a8f-cabdf1b38358>: cfxdb.globalschema.Organizations
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 002 for database table <3fb82ab2-430d-43a1-8200-fcd6355d0410>: cfxdb.globalschema.IndexOrganizationsByName
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 003 for database table <fa1ed0fc-304e-4f66-8092-d901df1735e4>: cfxdb.globalschema.Users
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 004 for database table <882a24e4-90cc-4823-94fe-c1d938daffe6>: cfxdb.globalschema.IndexUsersByPubkey
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 005 for database table <933447a3-dd79-4599-bd9a-e0d88d9b84cb>: cfxdb.globalschema.IndexUsersByEmail
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 006 for database table <c968886e-a2e2-490c-bc2a-6b684c3130f6>: cfxdb.globalschema.ActivationTokens
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 007 for database table <0f6a9014-2e39-4cfd-9f2b-f6ffd3d3deca>: cfxdb.globalschema.IndexActivationTokensByAuthidPubkey
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 008 for database table <1219e71c-a62c-415a-bd15-ddf45e3a658b>: cfxdb.globalschema.ManagementRealms
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 009 for database table <1d2e8045-ea2b-4456-be4a-7a234d3622d6>: cfxdb.globalschema.IndexManagementRealmByName
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 010 for database table <eccdfc57-5632-4ad4-9c2b-2ac11e9d389f>: cfxdb.globalschema.UserMrealmRoles
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 011 for database table <ae89d956-273a-4ce3-b63d-52b07ae35742>: cfxdb.globalschema.Nodes
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 012 for database table <1336c623-5f38-4397-ad5b-2e6b716b57b0>: cfxdb.globalschema.IndexNodesByPubkey
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 013 for database table <6d071a33-0577-4f72-a2e1-11182f60ab9c>: cfxdb.globalschema.IndexNodesByAuthid
2022-02-25T02:11:58+0500 [Router     1055011] Allocated new slot 014 for database table <e38f7bf1-2514-400c-8c30-a979b2138503>: cfxdb.globalschema.UsageRecords
2022-02-25T02:11:58+0500 [Router     1055011] Mailgun access key unconfigured (not in config, and no env var MAILGUN_KEY set)
2022-02-25T02:11:58+0500 [Router     1055011] <crossbar.worker.router.RouterController.set_service_session>(session=<crossbar.master.node.authenticator.Authenticator object at 0x7f2bfa8f8370>, realm="com.crossbario.fabric", authrole="authenticator")
2022-02-25T02:11:58+0500 [Router     1055011] Ok, master node authenticator ready on realm "com.crossbario.fabric" (session=3036875065702237, authid="4fd75eb9-380c-4d23-a665-f690a314f8cd", authrole="authenticator", controller=<crossbar.edge.worker.router.ExtRouterController object at 0x7f2bfa9c5eb0>) <crossbar.master.node.authenticator.Authenticator.onJoin>
2022-02-25T02:11:58+0500 [Router     1055011] component ready: crossbar.master.node.authenticator.Authenticator id=3036875065702237
2022-02-25T02:11:58+0500 [Controller 1054974] Router cfrouter1: component 'component001' started
2022-02-25T02:11:58+0500 [Controller 1054974] Order Router cfrouter1 to start Transport transport001
2022-02-25T02:11:58+0500 [Router     1055011] Starting router transport "transport001" <crossbar.worker.router.RouterController.start_router_transport>
2022-02-25T02:11:58+0500 [Router     1055011] Creating router transport for "transport001" ..
2022-02-25T02:11:58+0500 [Router     1055011] Router transport created for "transport001" [transport_class=<crossbar.worker.transport.RouterTransport>]
2022-02-25T02:11:58+0500 [Router     1055011] WampRawSocketServerFactory starting on '/home/om26er/Documents/master/sock1'
2022-02-25T02:11:58+0500 [Router     1055011] Router Unix domain socket transport started as transport "transport001" and listening on UDS path "sock1"
2022-02-25T02:11:58+0500 [Controller 1054974] Ok, Router cfrouter1 has started Transport transport001
2022-02-25T02:11:58+0500 [Controller 1054974] Order Router cfrouter1 to start Transport transport002
2022-02-25T02:11:58+0500 [Router     1055011] Starting router transport "transport002" <crossbar.worker.router.RouterController.start_router_transport>
2022-02-25T02:11:58+0500 [Router     1055011] Creating router transport for "transport002" ..
2022-02-25T02:11:58+0500 [Router     1055011] Router transport created for "transport002" [transport_class=<crossbar.worker.transport.RouterTransport>]
2022-02-25T02:11:58+0500 [Router     1055011] WampRawSocketServerFactory starting on '/home/om26er/Documents/master/sock2'
2022-02-25T02:11:58+0500 [Router     1055011] Router Unix domain socket transport started as transport "transport002" and listening on UDS path "sock2"
2022-02-25T02:11:58+0500 [Controller 1054974] Ok, Router cfrouter1 has started Transport transport002
2022-02-25T02:11:58+0500 [Controller 1054974] Order Router cfrouter1 to start Transport transport003
2022-02-25T02:11:58+0500 [Router     1055011] Starting router transport "transport003" <crossbar.worker.router.RouterController.start_router_transport>
2022-02-25T02:11:58+0500 [Router     1055011] Creating router transport for "transport003" ..
2022-02-25T02:11:58+0500 [Router     1055011] Router transport created for "transport003" [transport_class=<crossbar.worker.transport.RouterWebTransport>]
2022-02-25T02:11:58+0500 [Router     1055011] Created "registerme" Web service on root path "/" of Web transport "transport003"
2022-02-25T02:11:58+0500 [Router     1055011] Site starting on 9000
2022-02-25T02:11:58+0500 [Router     1055011] Router TCP/9000 transport started as transport "transport003" and listening on TCP port 9000
2022-02-25T02:11:58+0500 [Controller 1054974] Ok, Router cfrouter1 has started Transport transport003
2022-02-25T02:11:58+0500 [Controller 1054974] Order Transport transport003 to start Web Service webservice001
2022-02-25T02:11:58+0500 [Router     1055011] Starting "archive" Web service on path "autobahn" of transport "transport003" <crossbar.worker.transport.TransportController.start_web_transport_service>
2022-02-25T02:11:58+0500 [Router     1055011] ZipArchiveResource: downloading from "https://github.com/crossbario/autobahn-js-browser/archive/v20.2.1.zip"
2022-02-25T02:12:03+0500 [Router     1055011] ZipArchiveResource: file downloaded and cached locally [/home/om26er/Documents/master/autobahn-v20.2.1.zip]
2022-02-25T02:12:03+0500 [Router     1055011] ZipArchiveResource: archive file "/home/om26er/Documents/master/autobahn-v20.2.1.zip" verified (fingerprint b69cd17ac043..)
2022-02-25T02:12:03+0500 [Router     1055011] ZipArchiveResource: 22 files in ZIP archive
2022-02-25T02:12:03+0500 [Controller 1054974] Ok, Transport transport003 has started Web Service webservice001
2022-02-25T02:12:03+0500 [Controller 1054974] Order Transport transport003 to start Web Service webservice002
2022-02-25T02:12:03+0500 [Router     1055011] Starting "nodeinfo" Web service on path "info" of transport "transport003" <crossbar.worker.transport.TransportController.start_web_transport_service>
2022-02-25T02:12:03+0500 [Controller 1054974] Ok, Transport transport003 has started Web Service webservice002
2022-02-25T02:12:03+0500 [Controller 1054974] Order Transport transport003 to start Web Service webservice003
2022-02-25T02:12:03+0500 [Router     1055011] Starting "websocket" Web service on path "ws" of transport "transport003" <crossbar.worker.transport.TransportController.start_web_transport_service>
2022-02-25T02:12:03+0500 [Controller 1054974] Ok, Transport transport003 has started Web Service webservice003
2022-02-25T02:12:03+0500 [Controller 1054974] Ok, worker "Router cfrouter1" configured and ready!
2022-02-25T02:12:03+0500 [Controller 1054974] Order node to start "Container cfrealmmanager1" ..
2022-02-25T02:12:03+0500 [Controller 1054974] Starting container-worker "cfrealmmanager1" .. <crossbar.node.controller.NodeController.start_worker>
2022-02-25T02:12:03+0500 [Controller 1054974] worker-specific role "crossbar.worker.cfrealmmanager1" added on node management router realm "crossbar" <crossbar.master.node.node.FabricCenterNode._add_worker_role>

2022-02-25T02:12:04+0500 [Container  1055065] Starting container-worker "cfrealmmanager1" on node "center1" (personality "master") and local node management realm "crossbar" .. <crossbar.worker.container.ContainerController>
2022-02-25T02:12:04+0500 [Container  1055065] Running as PID 1055065 on CPython-EPollReactor
2022-02-25T02:12:04+0500 [Container  1055065] Entering event reactor ...
2022-02-25T02:12:04+0500 [Controller 1054974] attached session 4814085283926459 to realm "crossbar" (authid="crossbar.process.1055065", authrole="crossbar.worker.cfrealmmanager1") <crossbar.router.router.Router.attach>
2022-02-25T02:12:04+0500 [Container  1055065] Container worker "cfrealmmanager1" session 4814085283926459 initializing ..
2022-02-25T02:12:04+0500 [Container  1055065] Container worker "cfrealmmanager1" session ready
2022-02-25T02:12:04+0500 [Controller 1054974] Ok, node has started Container cfrealmmanager1
2022-02-25T02:12:04+0500 [Controller 1054974] Configuring Container cfrealmmanager1 ..
2022-02-25T02:12:04+0500 [Router     1055011] <crossbar.router.auth.anonymous.PendingAuthAnonymous.hello>(realm=com.crossbario.fabric, details.realm=com.crossbario.fabric, details.authid=None, details.authrole=None) [config={'type': 'static', 'role': 'trusted'}]
2022-02-25T02:12:04+0500 [Router     1055011] attached session 3131047464877036 to realm "com.crossbario.fabric" (authid="NGEV-QGEY-VFVR-C6SK-MGPH-W4X4", authrole="trusted") <crossbar.router.router.Router.attach>
2022-02-25T02:12:04+0500 [Container  1055065] Environment variable "$CROSSBARFX_METERING_URL" not set - needed in configuration "metering.submit.url"
2022-02-25T02:12:04+0500 [Container  1055065] Initialized DomainController from ComponentConfig.extra [node_key="ba20af741a18a437a08600d97e199e8fe1a998521cfd8af98b01ecc14f873fdf", meter_url="None"]
2022-02-25T02:12:04+0500 [Container  1055065] DomainController global database opened [dbpath=/home/om26er/Documents/master/.db-controller, maxsize=134217728]
2022-02-25T02:12:04+0500 [Container  1055065] SUPERUSER created and stored in database (oid=35f4b628-89f0-45fd-bfc4-9ed299ed78dc, email=superuser)
2022-02-25T02:12:04+0500 [Container  1055065] Default management realm enabled
2022-02-25T02:12:04+0500 [Container  1055065] Default management realm created [oid=23e7ac62-bbfc-4f74-b6cc-36490f2f2c9a]
2022-02-25T02:12:04+0500 [Container  1055065] Watch-to-pair enabled
2022-02-25T02:12:04+0500 [Container  1055065] Environment variable "$CROSSBARFX_WATCH_TO_PAIR" not set - needed in configuration "auto_default_mrealm.watch_to_pair"
2022-02-25T02:12:04+0500 [Container  1055065] skipping to watch "None" for node auto-pairing - not a directory!
2022-02-25T02:12:04+0500 [Container  1055065] Global master database full! Initiating EMERGENCY SHUTDOWN .. [0.0% free]
2022-02-25T02:12:04+0500 [Container  1055065] Master heartbeat loop started .. [period=300 secs]
2022-02-25T02:12:04+0500 [Container  1055065] Domain controller ready (realm="com.crossbario.fabric")!
2022-02-25T02:12:04+0500 [Container  1055065] Container component ready: component_id="component002", realm="com.crossbario.fabric", authrole="trusted", authid="NGEV-QGEY-VFVR-C6SK-MGPH-W4X4", session=3131047464877036 <crossbar.worker.container.ContainerController.onJoin>
2022-02-25T02:12:04+0500 [Controller 1054974] Node shutdown requested (restart=False, mode=None, reactor.running=True) ..
2022-02-25T02:12:04+0500 [Controller 1054974] FabricNodeControllerSession._shutdown(restart=False, mode=None)
2022-02-25T02:12:04+0500 [Controller 1054974] Container cfrealmmanager1: component 'component002' started
2022-02-25T02:12:04+0500 [Controller 1054974] Ok, worker "Container cfrealmmanager1" configured and ready!
2022-02-25T02:12:04+0500 [Controller 1054974] Ok, local node configuration ran successfully.
2022-02-25T02:12:04+0500 [Controller 1054974] attached session 1662081045683395 to realm "crossbar" (authid="None", authrole="trusted") <crossbar.router.router.Router.attach>
2022-02-25T02:12:04+0500 [Controller 1054974] FabricServiceNodeManager starting [dbpath=/home/om26er/Documents/master/.db-controller, maxsize=134217728]
2022-02-25T02:12:04+0500 [Controller 1054974] Initializing 1 management realms (parallel=False) ..
2022-02-25T02:12:04+0500 [Controller 1054974] Initializing management realm "default" [router_id="cfrouter1", container_id="cfcontainer1"] ..
2022-02-25T02:12:04+0500 [Router     1055011] Starting router realm "default" <crossbar.edge.worker.router.ExtRouterController.start_router_realm>
2022-02-25T02:12:04+0500 [Router     1055011] Starting router realm default <crossbar.worker.router.RouterController.start_router_realm>
2022-02-25T02:12:04+0500 [Router     1055011] RouterFactory.start_realm: router created for realm "default"
2022-02-25T02:12:04+0500 [Router     1055011] attached session 6527006953960273 to realm "default" (authid="routerworker-cfrouter1-realm-default-serviceagent", authrole="trusted") <crossbar.router.router.Router.attach>
2022-02-25T02:12:04+0500 [Router     1055011] <crossbar.router.service.RouterServiceAgent.onJoin>: realm service session attached to realm "default" [session_id=6527006953960273, authid="routerworker-cfrouter1-realm-default-serviceagent", authrole="trusted", on_ready=<Deferred at 0x7f2bf1ee6a60>]
2022-02-25T02:12:04+0500 [Router     1055011] <crossbar.worker.router.RouterController.set_service_session>(session=<crossbar.router.service.RouterServiceAgent object at 0x7f2bf1ee6370>, realm="default", authrole="trusted")
2022-02-25T02:12:04+0500 [Router     1055011] RouterServiceAgent started on realm="default" with authrole="trusted", authid="routerworker-cfrouter1-realm-default-serviceagent"
2022-02-25T02:12:04+0500 [Router     1055011] Realm "default" (name="default", authrole="trusted", authid="routerworker-cfrouter1-realm-default-serviceagent") started
2022-02-25T02:12:04+0500 [Router     1055011] Role owner-role named "owner" started on realm "default"
2022-02-25T02:12:04+0500 [Router     1055011] Role backend-role named "backend" started on realm "default"
2022-02-25T02:12:04+0500 [Router     1055011] Role node-role named "node" started on realm "default"
2022-02-25T02:12:04+0500 [Router     1055011] Role public-role named "public" started on realm "default"
2022-02-25T02:12:04+0500 [Controller 1054974] Starting container-worker "cfcontainer1" .. <crossbar.node.controller.NodeController.start_worker>
2022-02-25T02:12:04+0500 [Controller 1054974] worker-specific role "crossbar.worker.cfcontainer1" added on node management router realm "crossbar" <crossbar.master.node.node.FabricCenterNode._add_worker_role>
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 001 for database table <7099565b-7b44-4891-a0c8-83c7dbb60883>: cfxdb.mrealmschema.ApplicationRealms
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 002 for database table <89f3073a-32d5-497e-887d-7e930e9c26e6>: cfxdb.mrealmschema.IndexApplicationRealmByName
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 003 for database table <0275b858-890c-4879-945c-720235b093d7>: cfxdb.mrealmschema.IndexApplicationRealmByWebCluster
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 004 for database table <9808cb0b-1b55-4b3f-858e-39004cb11135>: cfxdb.mrealmschema.Principals
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 005 for database table <212f3455-6d4c-43ec-843d-53cd17e31974>: cfxdb.mrealmschema.IndexPrincipalByName
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 006 for database table <251c8620-425a-4eeb-ade9-4284e8670080>: cfxdb.mrealmschema.Credentials
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 007 for database table <45490b42-b167-4df6-ab1c-41d434390397>: cfxdb.mrealmschema.IndexCredentialsByAuth
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 008 for database table <ed0da771-e331-4d93-b50c-d371391cd7b9>: cfxdb.mrealmschema.IndexCredentialsByPrincipal
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 009 for database table <341083bb-edeb-461c-a6d4-38dddcda6ec9>: cfxdb.mrealmschema.Roles
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 010 for database table <71b990d1-4525-44cd-9ef8-3569de8b4c80>: cfxdb.mrealmschema.IndexRoleByName
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 011 for database table <5eabdb63-9c31-4c97-b514-7e8fbac7e143>: cfxdb.mrealmschema.ApplicationRealmRoleAssociations
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 012 for database table <f98ed35b-f8fb-47ba-81e1-3c014101464d>: cfxdb.mrealmschema.Permissions
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 013 for database table <6cdc21bf-353d-4477-8631-8eb039142ae9>: cfxdb.mrealmschema.IndexPermissionByUri
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 014 for database table <b054a230-c370-4c29-b5de-7e0148321b0a>: cfxdb.mrealmschema.RouterClusters
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 015 for database table <0c80c7a8-7536-4a74-8916-4922c0b72cb7>: cfxdb.mrealmschema.IndexRouterClusterByName
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 016 for database table <a091bad6-f14c-437c-8e30-e9be84380658>: cfxdb.mrealmschema.RouterClusterNodeMemberships
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 017 for database table <c019457b-d499-454f-9bf2-4f7e85079d8f>: cfxdb.mrealmschema.RouterWorkerGroups
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 018 for database table <4bb8ec14-4820-4061-8b2c-d1841e2686e1>: cfxdb.mrealmschema.IndexWorkerGroupByCluster
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 019 for database table <e3d326d2-6140-47a9-adf9-8e93b832717b>: cfxdb.mrealmschema.RouterWorkerGroupClusterPlacements
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 020 for database table <1a18739f-7224-4459-a446-6f1fedd760a7>: cfxdb.mrealmschema.IndexClusterPlacementByWorkerName
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 021 for database table <719d029f-e9d5-4b25-98e0-cf04d5a2648b>: cfxdb.mrealmschema.WebClusters
2022-02-25T02:12:04+0500 [Container  1055065] Allocated new slot 022 for database table <296c7d17-4769-4e40-8cb7-e6c394b93335>: cfxdb.mrealmschema.IndexWebClusterByName
2022-02-25T02:12:05+0500 [Container  1055065] Allocated new slot 023 for database table <e9801077-a629-470b-a4c9-4292a1f00d43>: cfxdb.mrealmschema.WebClusterNodeMemberships
2022-02-25T02:12:05+0500 [Container  1055065] Allocated new slot 024 for database table <a8803ca3-09a0-4d72-8728-2469de8d50ac>: cfxdb.mrealmschema.WebServices
2022-02-25T02:12:05+0500 [Container  1055065] Allocated new slot 025 for database table <f0b05bcf-f682-49bb-929e-ac252e9867fa>: cfxdb.mrealmschema.IndexWebServiceByPath
2022-02-25T02:12:05+0500 [Container  1055065] Allocated new slot 026 for database table <d23d4dbb-5d5c-4ccc-b72a-0ff18363169f>: cfxdb.mrealmschema.IndexWebClusterWebServices
2022-02-25T02:12:05+0500 [Container  1055065] Allocated new slot 027 for database table <256a071f-5aeb-47f3-8786-97cd8281bdb7>: cfxdb.log.mnode_logs.MNodeLogs
2022-02-25T02:12:05+0500 [Container  1055065] Allocated new slot 028 for database table <5ceaa500-4832-451c-adf4-4fc4968cece0>: cfxdb.log.mworker_logs.MWorkerLogs
2022-02-25T02:12:05+0500 [Container  1055065] Usage metering: aggregated and stored period from 2022-02-24T21:07:00.000000000 to 2022-02-24T21:12:00.000000000 (300 seconds) usage metering data for mrealm "23e7ac62-bbfc-4f74-b6cc-36490f2f2c9a"
2022-02-25T02:12:05+0500 [Container  1055065] Usage metering: finished aggregating [1 intervals stored]
2022-02-25T02:12:05+0500 [Container  1055065] Skipping to submit metering records - no metering URL set!
2022-02-25T02:12:05+0500 [Container  1055065] Master heartbeat loop iteration 1 finished in 158 ms (database 134.2 MB used, 0.0% free)

2022-02-25T02:12:05+0500 [Controller 1054974] sending TERM to subprocess 1055011
2022-02-25T02:12:05+0500 [Controller 1054974] waiting for 1055011 to exit...
2022-02-25T02:12:05+0500 [Controller 1054974] sending TERM to subprocess 1055065
2022-02-25T02:12:05+0500 [Controller 1054974] waiting for 1055065 to exit...
2022-02-25T02:12:05+0500 [Router     1055011] Native worker received SIGTERM - shutting down ..
2022-02-25T02:12:05+0500 [Router     1055011] Shutdown of worker requested!
2022-02-25T02:12:05+0500 [Router     1055011] detached session 3131047464877036 from realm "com.crossbario.fabric" (authid="NGEV-QGEY-VFVR-C6SK-MGPH-W4X4", authrole="trusted", detached 1 sessions total) <crossbar.router.router.Router.detach>
2022-02-25T02:12:05+0500 [Container  1055065] Native worker received SIGTERM - shutting down ..
2022-02-25T02:12:05+0500 [Container  1055065] session closed with reason wamp.close.transport_lost [WAMP transport was lost without closing the session 3131047464877036 before]
2022-02-25T02:12:05+0500 [Container  1055065] Closed connection to 'component002'
2022-02-25T02:12:05+0500 [Container  1055065] Container is hosting no more components: continue running in exit mode <shutdown-manual>
2022-02-25T02:12:05+0500 [Container  1055065] <crossbar.worker.container.ContainerController.start_component.<locals>._component_closed>: now restarting previously closed component component002 automatically .. [restart_mode=restart-always, was_clean=True]
2022-02-25T02:12:05+0500 [Controller 1054974] detached session 4934916645490666 from realm "crossbar" (authid="crossbar.process.1055011", authrole="crossbar.worker.cfrouter1", detached 1 sessions total) <crossbar.router.router.Router.detach>
2022-02-25T02:12:05+0500 [Container  1055065] Connection to node controller closed cleanly
2022-02-25T02:12:05+0500 [Container  1055065] Lost connection to component 'component002' uncleanly
2022-02-25T02:12:05+0500 [Container  1055065] Container is hosting no more components: continue running in exit mode <shutdown-manual>
2022-02-25T02:12:05+0500 [Router     1055011] <crossbar.router.auth.anonymous.PendingAuthAnonymous.hello>(realm=com.crossbario.fabric, details.realm=com.crossbario.fabric, details.authid=None, details.authrole=None) [config={'type': 'static', 'role': 'trusted'}]
2022-02-25T02:12:05+0500 [Router     1055011] attached session 8187209495982737 to realm "com.crossbario.fabric" (authid="NXWQ-LU7X-C3AM-X66W-37V4-93RA", authrole="trusted") <crossbar.router.router.Router.attach>
2022-02-25T02:12:05+0500 [Router     1055011] RouterApplicationSession.close(session=<crossbar.master.node.authenticator.Authenticator object at 0x7f2bfa8f8370>)
2022-02-25T02:12:05+0500 [Router     1055011] stopped component: crossbar.master.node.authenticator.Authenticator id=3036875065702237
2022-02-25T02:12:05+0500 [Router     1055011] component 'component001' disconnected
2022-02-25T02:12:05+0500 [Router     1055011] RouterApplicationSession.close(session=<crossbar.master.node.authenticator.Authenticator object at 0x7f2bfa8f8370>)
2022-02-25T02:12:05+0500 [Router     1055011] detached session 3036875065702237 from realm "com.crossbario.fabric" (authid="4fd75eb9-380c-4d23-a665-f690a314f8cd", authrole="authenticator", detached 1 sessions total) <crossbar.router.router.Router.detach>
2022-02-25T02:12:05+0500 [Router     1055011] cannot detach session "3036875065702237": session not currently attached
2022-02-25T02:12:05+0500 [Router     1055011] detached session 8187209495982737 from realm "com.crossbario.fabric" (authid="NXWQ-LU7X-C3AM-X66W-37V4-93RA", authrole="trusted", detached 1 sessions total) <crossbar.router.router.Router.detach>
2022-02-25T02:12:05+0500 [Controller 1054974] <crossbar.router.session.RouterSession.onMessage> PUBLISH message received while session is not yet joined
2022-02-25T02:12:05+0500 [Router     1055011] Connection to node controller closed cleanly
2022-02-25T02:12:05+0500 [Router     1055011] (TCP Port 9000 Closed)
2022-02-25T02:12:05+0500 [Router     1055011] (UNIX Port /home/om26er/Documents/master/sock2 Closed)
2022-02-25T02:12:05+0500 [Router     1055011] (UNIX Port /home/om26er/Documents/master/sock1 Closed)
2022-02-25T02:12:05+0500 [Controller 1054974] Native worker connection closed cleanly.
2022-02-25T02:12:05+0500 [Controller 1054974] detached session 4814085283926459 from realm "crossbar" (authid="crossbar.process.1055065", authrole="crossbar.worker.cfrealmmanager1", detached 1 sessions total) <crossbar.router.router.Router.detach>
2022-02-25T02:12:05+0500 [Controller 1054974] Node worker cfrealmmanager1 ended successfully
2022-02-25T02:12:05+0500 [Controller 1054974] Checking for node shutdown: worker_exit_success=True, shutdown_requested=True, node_shutdown_triggers=['shutdown_on_last_worker_exit']
2022-02-25T02:12:05+0500 [Controller 1054974] Native worker connection closed cleanly.
2022-02-25T02:12:05+0500 [Controller 1054974] Node worker cfrouter1 ended successfully
2022-02-25T02:12:05+0500 [Controller 1054974] Checking for node shutdown: worker_exit_success=True, shutdown_requested=True, node_shutdown_triggers=['shutdown_on_last_worker_exit']
om26er commented 2 years ago

The error happens close to the database creation part, I wonder if cfxdb is related

om26er commented 2 years ago

More verbose logs https://gist.github.com/om26er/2fcaf460e36ee69fa4968c15aadbbb2b

oberstet commented 2 years ago

2022-02-25T02:21:03+0500 [Container 1057242 zlmdb._database.Database] No slot found in database for DB table <89f3073a-32d5-497e-887d-7e930e9c26e6>: 2

definitely sth weird. I'd scratch all your DB files and retry ... this will auto-create new db slots upon first start

oberstet commented 2 years ago

one more note: I did some bigger changes / updates to the zlmdb and cfxdb stuff - without thinking too much about not breaking existing DB files - which we definitely can and should do looking forward. means: then evolving the DB is possible with backwards compatible DB files.

om26er commented 2 years ago

I have tried with clearing the database, still the same result, also verified on multiple machines. Investigating...

om26er commented 2 years ago

Ok, there is a hint in the logs

Global master database full! Initiating EMERGENCY SHUTDOWN .. [0.0% free]
oberstet commented 2 years ago

fixed via https://github.com/crossbario/crossbar/pull/1953