search

inmanta / inmanta-core

Inmanta is an automation and orchestration tool
https://inmanta.com
Apache License 2.0
27 stars 7 forks source link

Test case test_agent_actions unstable on iso3 branch #2993

Closed arnaudsjs closed 2 years ago

arnaudsjs commented 3 years ago 
______________________________ test_agent_actions ______________________________

server = <inmanta.server.protocol.Server object at 0x7f3ab7fff358>
client = <inmanta.protocol.endpoints.Client object at 0x7f3ab7fff2b0>
async_finalizer = <conftest.AsyncCleaner object at 0x7f3ab56fc320>

    @pytest.mark.asyncio
    async def test_agent_actions(server, client, async_finalizer):
        """
        Test the agent_action() and the all_agents_action() API call.
        """
        config.Config.set("config", "agent-deploy-interval", "0")
        config.Config.set("config", "agent-repair-interval", "0")
        agent_manager = server.get_slice(SLICE_AGENT_MANAGER)

        result = await client.create_project("test")
        assert result.code == 200
        project_id = result.result["project"]["id"]

        result = await client.create_environment(project_id=project_id, name="test1")
        env1_id = UUID(result.result["environment"]["id"])
        result = await client.create_environment(project_id=project_id, name="test2")
        env2_id = UUID(result.result["environment"]["id"])

        env_to_agent_map: Dict[UUID, agent.Agent] = {}

        async def start_agent(env_id: UUID, agent_names: List[str]) -> None:
            for agent_name in agent_names:
                await data.Agent(environment=env_id, name=agent_name, paused=False).insert()

            agent_map = {agent_name: "localhost" for agent_name in agent_names}
            a = agent.Agent(hostname="node1", environment=env_id, agent_map=agent_map, code_loader=False)
            for agent_name in agent_names:
                await a.add_end_point_name(agent_name)
            await a.start()
            async_finalizer(a.stop)
            env_to_agent_map[env_id] = a

        await start_agent(env1_id, ["agent1", "agent2"])
        await start_agent(env2_id, ["agent1"])

        await retry_limited(lambda: len(agent_manager.sessions) == 2, 10)

        async def assert_agents_paused(expected_statuses: Dict[Tuple[UUID, str], bool]) -> None:
            for (env_id, agent_name), paused in expected_statuses.items():
                # Check in-memory session state
                live_session_found = (env_id, agent_name) in agent_manager.tid_endpoint_to_session
                assert live_session_found != paused
                # Check database state
                agent_from_db = await data.Agent.get_one(environment=env_id, name=agent_name)
                assert agent_from_db.paused == paused
                assert (agent_from_db.primary is None) == paused
                if not paused:
                    live_session = agent_manager.tid_endpoint_to_session[(env_id, agent_name)]
                    agent_instance = await data.AgentInstance.get_by_id(agent_from_db.primary)
                    assert agent_instance.process == live_session.id
                # Check agent state
                assert env_to_agent_map[env_id]._instances[agent_name].is_enabled() != paused

        await assert_agents_paused(
>           expected_statuses={(env1_id, "agent1"): False, (env1_id, "agent2"): False, (env2_id, "agent1"): False}
        )

tests/test_agent_manager.py:737: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

expected_statuses = {(UUID('4aa3efdf-8050-4f25-8097-24b5d1e659c3'), 'agent1'): False, (UUID('4aa3efdf-8050-4f25-8097-24b5d1e659c3'), 'agent2'): False, (UUID('844c5fe4-37f9-4328-902c-91512e5129a6'), 'agent1'): False}

    async def assert_agents_paused(expected_statuses: Dict[Tuple[UUID, str], bool]) -> None:
        for (env_id, agent_name), paused in expected_statuses.items():
            # Check in-memory session state
            live_session_found = (env_id, agent_name) in agent_manager.tid_endpoint_to_session
            assert live_session_found != paused
            # Check database state
            agent_from_db = await data.Agent.get_one(environment=env_id, name=agent_name)
            assert agent_from_db.paused == paused
>           assert (agent_from_db.primary is None) == paused
E           assert True == False
E             +True
E             -False

tests/test_agent_manager.py:728: AssertionError
------------------------------ Captured log setup ------------------------------
DEBUG    asyncio:selector_events.py:54 Using selector: EpollSelector
WARNING  inmanta.config:config.py:166 Config name token not defined in section server_rest_transport
INFO     inmanta.server.bootloader:bootloader.py:100 Discoverd extensions: core
INFO     inmanta.server.server:server.py:63 Starting server endpoint
DEBUG    inmanta.server.protocol:protocol.py:152 Starting Server Rest Endpoint
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.database
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.session
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.agentmanager
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.compiler
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.server
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.autostarted_agent_manager
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.file
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.code
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.dryrun
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.resource
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.orchestration
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.environment
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.metrics
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.parameters
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.project
DEBUG    inmanta.server.protocol:protocol.py:157 Pre Starting core.transport
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.database
DEBUG    inmanta.data:__init__.py:2803 Connecting data classes
INFO     inmanta.server.services.databaseservice:databaseservice.py:71 Connected to PostgreSQL database inmanta4488435686 on localhost:14866
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.session
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.agentmanager
DEBUG    inmanta.server.agentmanager:agentmanager.py:448 Cleaning server session DB
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.compiler
DEBUG    inmanta.util:util.py:152 Scheduling action <bound method CompilerService._cleanup of <inmanta.server.services.compilerservice.CompilerService object at 0x7f3ab678c748>> every 3600 seconds with initial delay 0
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.server
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.autostarted_agent_manager
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.file
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.code
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.dryrun
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.resource
DEBUG    inmanta.util:util.py:152 Scheduling action <bound method ResourceAction.purge_logs of <class 'inmanta.data.ResourceAction'>> every 3600 seconds with initial delay 3600
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.orchestration
DEBUG    inmanta.util:util.py:152 Scheduling action <bound method OrchestrationService._purge_versions of <inmanta.server.services.orchestrationservice.OrchestrationService object at 0x7f3ab6792c50>> every 3600 seconds with initial delay 3600
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.environment
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.metrics
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.parameters
DEBUG    inmanta.util:util.py:152 Scheduling action <bound method ParameterService.renew_expired_facts of <inmanta.server.services.paramservice.ParameterService object at 0x7f3ab67a5588>> every 1200 seconds with initial delay 1200
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.project
DEBUG    inmanta.server.protocol:protocol.py:164 Starting core.transport
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/heartbeat and methods POST, PUT
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/docs and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/serverstatus and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/notify/(?P<id>[^/]+) and methods POST, GET, HEAD
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/agent/(?P<name>[^/]+)/(?P<action>[^/]+) and methods POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/agents/(?P<action>[^/]+) and methods POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/agentproc/(?P<id>[^/]+) and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/agentrecovery and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/agentproc and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/agent and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/agent/(?P<id>[^/]+) and methods POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/compiledata/(?P<id>[^/]+) and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/compilequeue and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/compilereport/(?P<id>[^/]+) and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/compilereport and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/project and methods PUT, GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/project/(?P<id>[^/]+) and methods DELETE, GET, POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/project and methods PUT, GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/project/(?P<id>[^/]+) and methods DELETE, GET, POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/decommission/(?P<id>[^/]+) and methods DELETE, POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/environment and methods PUT, GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/environment_auth and methods POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/environment/(?P<id>[^/]+) and methods DELETE, GET, POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/environment_settings/(?P<id>[^/]+) and methods DELETE, GET, POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/decommission/(?P<id>[^/]+) and methods DELETE, POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/environment and methods PUT, GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/environment_auth and methods POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/environment/(?P<id>[^/]+) and methods DELETE, GET, POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/environment_settings/(?P<id>[^/]+) and methods DELETE, GET, POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/environment_settings and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/actions/environment/halt and methods POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/environment_settings and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/actions/environment/resume and methods POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/filediff and methods POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/file/(?P<id>[^/]+) and methods GET, HEAD, PUT
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/file and methods POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/code/(?P<id>[^/]+) and methods GET, PUT
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/codebatched/(?P<id>[^/]+) and methods PUT
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/parameter/(?P<id>[^/]+) and methods DELETE, GET, PUT
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/parameter and methods POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/parameters and methods PUT
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/resource/(?P<id>[^/]+) and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/resource_actions and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/resource and methods GET, POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/version/(?P<id>[^/]+) and methods DELETE, GET, POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/deploy and methods POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/version and methods GET, PUT
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v2/reserve_version and methods POST
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/dryrun and methods GET
DEBUG    inmanta.protocol.rest.server:server.py:297 Registering handler(s) for url /api/v1/dryrun/(?P<id>[^/]+) and methods GET, POST, PUT
INFO     inmanta.protocol.rest.server:server.py:318 Server listening on 127.0.0.1:51923
DEBUG    inmanta.protocol.rest.server:server.py:321 Start REST transport
INFO     inmanta.util:util.py:155 Calling <bound method CompilerService._cleanup of <inmanta.server.services.compilerservice.CompilerService object at 0x7f3ab678c748>>
DEBUG    inmanta.protocol.endpoints:endpoints.py:339 Start transport for client client
INFO     inmanta.server.services.compilerservice:compilerservice.py:380 Cleaning up compile reports that are older than 2021-05-20 05:58:18.792268
------------------------------ Captured log call -------------------------------
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section client_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server PUT http://localhost:51923/api/v1/project
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method ProjectService.create_project of <inmanta.server.services.projectservice.ProjectService object at 0x7f3ab67a52e8>>(name='test', project_id='None')
INFO     tornado.access:web.py:2243 200 PUT /api/v1/project (127.0.0.1) 4.95ms
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section client_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server PUT http://localhost:51923/api/v1/environment
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method EnvironmentService.create_environment of <inmanta.server.services.environmentservice.EnvironmentService object at 0x7f3ab67a5710>>(project_id='0369ddf...', name='test1', repository='None', branch='None', environment_id='None')
INFO     tornado.access:web.py:2243 200 PUT /api/v1/environment (127.0.0.1) 6.74ms
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section client_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server PUT http://localhost:51923/api/v1/environment
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method EnvironmentService.create_environment of <inmanta.server.services.environmentservice.EnvironmentService object at 0x7f3ab67a5710>>(project_id='0369ddf...', name='test2', repository='None', branch='None', environment_id='None')
INFO     tornado.access:web.py:2243 200 PUT /api/v1/environment (127.0.0.1) 5.21ms
INFO     inmanta.agent.agent:agent.py:1124 Adding endpoint agent1
DEBUG    inmanta.protocol.endpoints:endpoints.py:115 Adding 'agent1' as endpoint
INFO     inmanta.agent.agent:agent.py:1124 Adding endpoint agent2
DEBUG    inmanta.protocol.endpoints:endpoints.py:115 Adding 'agent2' as endpoint
DEBUG    inmanta.protocol.endpoints:endpoints.py:339 Start transport for client agent
INFO     inmanta.agent.agent:agent.py:1124 Adding endpoint node1
DEBUG    inmanta.protocol.endpoints:endpoints.py:115 Adding 'node1' as endpoint
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server POST http://localhost:51923/api/v1/heartbeat
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
INFO     inmanta.agent.agent:agent.py:1124 Adding endpoint agent1
DEBUG    inmanta.protocol.endpoints:endpoints.py:115 Adding 'agent1' as endpoint
DEBUG    inmanta.protocol.endpoints:endpoints.py:339 Start transport for client agent
INFO     inmanta.agent.agent:agent.py:1124 Adding endpoint node1
DEBUG    inmanta.protocol.endpoints:endpoints.py:115 Adding 'node1' as endpoint
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server POST http://localhost:51923/api/v1/heartbeat
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method SessionManager.heartbeat of <inmanta.server.protocol.SessionManager object at 0x7f3ab678cbe0>>(sid='c58b67c...', endpoint_names='['node1...', nodename='jenkins...', no_hang='True', env='<inmant...')
DEBUG    inmanta.server.protocol:protocol.py:644 Received heartbeat from jenkins-runner-5.ii.inmanta.com for agents node1,agent2,agent1 in 4aa3efdf-8050-4f25-8097-24b5d1e659c3
DEBUG    inmanta.server.protocol:protocol.py:625 New session with id c58b67ce-be9f-11eb-a50e-005056b8e25e on node jenkins-runner-5.ii.inmanta.com for env 4aa3efdf-8050-4f25-8097-24b5d1e659c3 with endpoints {'node1', 'agent2', 'agent1'}
DEBUG    inmanta.protocol.endpoints:endpoints.py:339 Start transport for client c58b67ce-be9f-11eb-a50e-005056b8e25e
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.server.agentmanager:agentmanager.py:376 New session c58b67ce-be9f-11eb-a50e-005056b8e25e for agents {'node1', 'agent2', 'agent1'} on jenkins-runner-5.ii.inmanta.com
DEBUG    inmanta.server.protocol:protocol.py:648 Let node jenkins-runner-5.ii.inmanta.com wait for method calls to become available. (long poll)
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method SessionManager.heartbeat of <inmanta.server.protocol.SessionManager object at 0x7f3ab678cbe0>>(sid='c58c928...', endpoint_names='['node1...', nodename='jenkins...', no_hang='True', env='<inmant...')
DEBUG    inmanta.server.protocol:protocol.py:644 Received heartbeat from jenkins-runner-5.ii.inmanta.com for agents node1,agent1 in 844c5fe4-37f9-4328-902c-91512e5129a6
DEBUG    inmanta.server.protocol:protocol.py:625 New session with id c58c9284-be9f-11eb-a50e-005056b8e25e on node jenkins-runner-5.ii.inmanta.com for env 844c5fe4-37f9-4328-902c-91512e5129a6 with endpoints {'node1', 'agent1'}
DEBUG    inmanta.protocol.endpoints:endpoints.py:339 Start transport for client c58c9284-be9f-11eb-a50e-005056b8e25e
DEBUG    inmanta.server.protocol:protocol.py:648 Let node jenkins-runner-5.ii.inmanta.com wait for method calls to become available. (long poll)
DEBUG    inmanta.server.agentmanager:agentmanager.py:502 set session c58b67ce-be9f-11eb-a50e-005056b8e25e as primary for agent node1 in env 4aa3efdf-8050-4f25-8097-24b5d1e659c3
DEBUG    inmanta.server.agentmanager:agentmanager.py:502 set session c58b67ce-be9f-11eb-a50e-005056b8e25e as primary for agent agent2 in env 4aa3efdf-8050-4f25-8097-24b5d1e659c3
DEBUG    inmanta.server.agentmanager:agentmanager.py:502 set session c58b67ce-be9f-11eb-a50e-005056b8e25e as primary for agent agent1 in env 4aa3efdf-8050-4f25-8097-24b5d1e659c3
DEBUG    inmanta.server.agentmanager:agentmanager.py:376 New session c58c9284-be9f-11eb-a50e-005056b8e25e for agents {'node1', 'agent1'} on jenkins-runner-5.ii.inmanta.com
DEBUG    inmanta.server.protocol:protocol.py:413 Putting call f16f8e2a-d54f-4779-b298-799486d1b2c9: POST /api/v1/agentstate for agent c58b67ce-be9f-11eb-a50e-005056b8e25e in queue
DEBUG    inmanta.server.protocol:protocol.py:413 Putting call 662efb74-1894-4c80-9ff5-7ae8497f1316: POST /api/v1/agentstate for agent c58b67ce-be9f-11eb-a50e-005056b8e25e in queue
DEBUG    inmanta.server.protocol:protocol.py:413 Putting call f19b732d-f6cf-477c-a0e4-3b70a3f5768e: POST /api/v1/agentstate for agent c58b67ce-be9f-11eb-a50e-005056b8e25e in queue
DEBUG    inmanta.server.protocol:protocol.py:651 Pushing 3 method calls to node jenkins-runner-5.ii.inmanta.com
INFO     tornado.access:web.py:2243 200 POST /api/v1/heartbeat (127.0.0.1) 16.33ms
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server POST http://localhost:51923/api/v1/heartbeat
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server GET http://localhost:51923/api/v1/agentrecovery?sid=c58b67ce-be9f-11eb-a50e-005056b8e25e&agent=agent1
DEBUG    inmanta.protocol.endpoints:endpoints.py:266 Received call through heartbeat: f16f8e2a-d54f-4779-b298-799486d1b2c9 POST /api/v1/agentstate
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method Agent.set_state of <inmanta.agent.agent.Agent object at 0x7f3ab56fcef0>>(agent='node1', enabled='True')
INFO     inmanta.agent.agent.node1:agent.py:653 Agent assuming primary role for node1
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server PUT http://localhost:51923/api/v1/heartbeat
DEBUG    inmanta.protocol.endpoints:endpoints.py:266 Received call through heartbeat: 662efb74-1894-4c80-9ff5-7ae8497f1316 POST /api/v1/agentstate
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method Agent.set_state of <inmanta.agent.agent.Agent object at 0x7f3ab56fcef0>>(agent='agent2', enabled='True')
INFO     inmanta.agent.agent.agent2:agent.py:653 Agent assuming primary role for agent2
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server PUT http://localhost:51923/api/v1/heartbeat
DEBUG    inmanta.protocol.endpoints:endpoints.py:266 Received call through heartbeat: f19b732d-f6cf-477c-a0e4-3b70a3f5768e POST /api/v1/agentstate
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method Agent.set_state of <inmanta.agent.agent.Agent object at 0x7f3ab56fcef0>>(agent='agent1', enabled='True')
INFO     inmanta.agent.agent.agent1:agent.py:653 Agent assuming primary role for agent1
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server PUT http://localhost:51923/api/v1/heartbeat
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method SessionManager.heartbeat_reply of <inmanta.server.protocol.SessionManager object at 0x7f3ab678cbe0>>(sid='c58b67c...', reply_id='f16f8e2...', data='{'resul...')
INFO     tornado.access:web.py:2243 200 PUT /api/v1/heartbeat (127.0.0.1) 3.18ms
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method SessionManager.heartbeat_reply of <inmanta.server.protocol.SessionManager object at 0x7f3ab678cbe0>>(sid='c58b67c...', reply_id='662efb7...', data='{'resul...')
INFO     tornado.access:web.py:2243 200 PUT /api/v1/heartbeat (127.0.0.1) 3.95ms
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method SessionManager.heartbeat_reply of <inmanta.server.protocol.SessionManager object at 0x7f3ab678cbe0>>(sid='c58b67c...', reply_id='f19b732...', data='{'resul...')
INFO     tornado.access:web.py:2243 200 PUT /api/v1/heartbeat (127.0.0.1) 5.06ms
DEBUG    inmanta.server.agentmanager:agentmanager.py:502 set session c58c9284-be9f-11eb-a50e-005056b8e25e as primary for agent node1 in env 844c5fe4-37f9-4328-902c-91512e5129a6
DEBUG    inmanta.server.agentmanager:agentmanager.py:502 set session c58c9284-be9f-11eb-a50e-005056b8e25e as primary for agent agent1 in env 844c5fe4-37f9-4328-902c-91512e5129a6
DEBUG    inmanta.server.protocol:protocol.py:413 Putting call cebc02bd-5272-4d4f-a25b-946a141a394a: POST /api/v1/agentstate for agent c58c9284-be9f-11eb-a50e-005056b8e25e in queue
DEBUG    inmanta.server.protocol:protocol.py:413 Putting call 32e34717-b817-44e1-a94a-ed62fa9b7cee: POST /api/v1/agentstate for agent c58c9284-be9f-11eb-a50e-005056b8e25e in queue
DEBUG    inmanta.server.protocol:protocol.py:651 Pushing 2 method calls to node jenkins-runner-5.ii.inmanta.com
INFO     tornado.access:web.py:2243 200 POST /api/v1/heartbeat (127.0.0.1) 38.64ms
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server POST http://localhost:51923/api/v1/heartbeat
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server GET http://localhost:51923/api/v1/agentrecovery?sid=c58c9284-be9f-11eb-a50e-005056b8e25e&agent=agent1
DEBUG    inmanta.protocol.endpoints:endpoints.py:266 Received call through heartbeat: cebc02bd-5272-4d4f-a25b-946a141a394a POST /api/v1/agentstate
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method Agent.set_state of <inmanta.agent.agent.Agent object at 0x7f3ab56fceb8>>(agent='node1', enabled='True')
INFO     inmanta.agent.agent.node1:agent.py:653 Agent assuming primary role for node1
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server PUT http://localhost:51923/api/v1/heartbeat
DEBUG    inmanta.protocol.endpoints:endpoints.py:266 Received call through heartbeat: 32e34717-b817-44e1-a94a-ed62fa9b7cee POST /api/v1/agentstate
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method Agent.set_state of <inmanta.agent.agent.Agent object at 0x7f3ab56fceb8>>(agent='agent1', enabled='True')
INFO     inmanta.agent.agent.agent1:agent.py:653 Agent assuming primary role for agent1
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server PUT http://localhost:51923/api/v1/heartbeat
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method AgentManager.get_state of <inmanta.server.agentmanager.AgentManager object at 0x7f3ab678c390>>(sid='c58b67c...', agent='agent1', env='<inmant...')
INFO     tornado.access:web.py:2243 200 GET /api/v1/agentrecovery?sid=c58b67ce-be9f-11eb-a50e-005056b8e25e&agent=agent1 (127.0.0.1) 19.08ms
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method SessionManager.heartbeat of <inmanta.server.protocol.SessionManager object at 0x7f3ab678cbe0>>(sid='c58b67c...', endpoint_names='['node1...', nodename='jenkins...', no_hang='False', env='<inmant...')
DEBUG    inmanta.server.protocol:protocol.py:644 Received heartbeat from jenkins-runner-5.ii.inmanta.com for agents node1,agent2,agent1 in 4aa3efdf-8050-4f25-8097-24b5d1e659c3
DEBUG    inmanta.server.protocol:protocol.py:637 Seen session with id c58b67ce-be9f-11eb-a50e-005056b8e25e; endpoints: {'node1', 'agent2', 'agent1'}
DEBUG    inmanta.server.agentmanager:agentmanager.py:341 Adding endpoints set() to session c58b67ce-be9f-11eb-a50e-005056b8e25e on jenkins-runner-5.ii.inmanta.com
DEBUG    inmanta.server.agentmanager:agentmanager.py:343 Removing endpoints set() from session c58b67ce-be9f-11eb-a50e-005056b8e25e on jenkins-runner-5.ii.inmanta.com
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server GET http://localhost:51923/api/v1/agentrecovery?sid=c58b67ce-be9f-11eb-a50e-005056b8e25e&agent=agent2
DEBUG    inmanta.server.protocol:protocol.py:648 Let node jenkins-runner-5.ii.inmanta.com wait for method calls to become available. (long poll)
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method SessionManager.heartbeat_reply of <inmanta.server.protocol.SessionManager object at 0x7f3ab678cbe0>>(sid='c58c928...', reply_id='cebc02b...', data='{'resul...')
INFO     tornado.access:web.py:2243 200 PUT /api/v1/heartbeat (127.0.0.1) 4.59ms
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method SessionManager.heartbeat_reply of <inmanta.server.protocol.SessionManager object at 0x7f3ab678cbe0>>(sid='c58c928...', reply_id='32e3471...', data='{'resul...')
INFO     tornado.access:web.py:2243 200 PUT /api/v1/heartbeat (127.0.0.1) 5.07ms
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method SessionManager.heartbeat of <inmanta.server.protocol.SessionManager object at 0x7f3ab678cbe0>>(sid='c58c928...', endpoint_names='['node1...', nodename='jenkins...', no_hang='False', env='<inmant...')
DEBUG    inmanta.server.protocol:protocol.py:644 Received heartbeat from jenkins-runner-5.ii.inmanta.com for agents node1,agent1 in 844c5fe4-37f9-4328-902c-91512e5129a6
DEBUG    inmanta.server.protocol:protocol.py:637 Seen session with id c58c9284-be9f-11eb-a50e-005056b8e25e; endpoints: {'node1', 'agent1'}
DEBUG    inmanta.server.agentmanager:agentmanager.py:341 Adding endpoints set() to session c58c9284-be9f-11eb-a50e-005056b8e25e on jenkins-runner-5.ii.inmanta.com
DEBUG    inmanta.server.agentmanager:agentmanager.py:343 Removing endpoints set() from session c58c9284-be9f-11eb-a50e-005056b8e25e on jenkins-runner-5.ii.inmanta.com
DEBUG    inmanta.server.protocol:protocol.py:648 Let node jenkins-runner-5.ii.inmanta.com wait for method calls to become available. (long poll)
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method AgentManager.get_state of <inmanta.server.agentmanager.AgentManager object at 0x7f3ab678c390>>(sid='c58b67c...', agent='agent2', env='<inmant...')
INFO     tornado.access:web.py:2243 200 GET /api/v1/agentrecovery?sid=c58b67ce-be9f-11eb-a50e-005056b8e25e&agent=agent2 (127.0.0.1) 6.51ms
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server GET http://localhost:51923/api/v1/agentrecovery?sid=c58b67ce-be9f-11eb-a50e-005056b8e25e&agent=node1
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method AgentManager.get_state of <inmanta.server.agentmanager.AgentManager object at 0x7f3ab678c390>>(sid='c58c928...', agent='agent1', env='<inmant...')
INFO     tornado.access:web.py:2243 200 GET /api/v1/agentrecovery?sid=c58c9284-be9f-11eb-a50e-005056b8e25e&agent=agent1 (127.0.0.1) 24.53ms
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest.client:client.py:82 Getting config in section agent_rest_transport
DEBUG    inmanta.protocol.rest.client:client.py:114 Calling server GET http://localhost:51923/api/v1/agentrecovery?sid=c58c9284-be9f-11eb-a50e-005056b8e25e&agent=node1
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method AgentManager.get_state of <inmanta.server.agentmanager.AgentManager object at 0x7f3ab678c390>>(sid='c58b67c...', agent='node1', env='<inmant...')
INFO     tornado.access:web.py:2243 200 GET /api/v1/agentrecovery?sid=c58b67ce-be9f-11eb-a50e-005056b8e25e&agent=node1 (127.0.0.1) 8.33ms
DEBUG    inmanta.protocol.rest.server:server.py:122 HTTP version of request: HTTP/1.1
DEBUG    inmanta.protocol.rest:__init__.py:438 Calling method <bound method AgentManager.get_state of <inmanta.server.agentmanager.AgentManager object at 0x7f3ab678c390>>(sid='c58c928...', agent='node1', env='<inmant...')
INFO     tornado.access:web.py:2243 200 GET /api/v1/agentrecovery?sid=c58c9284-be9f-11eb-a50e-005056b8e25e&agent=node1 (127.0.0.1) 4.03ms
---------------------------- Captured log teardown -----------------------------
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.transport
DEBUG    inmanta.server.protocol:protocol.py:530 Stopping Server Rest Endpoint
DEBUG    inmanta.protocol.rest.server:server.py:328 Stopping Server Rest Endpoint
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.project
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.parameters
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.metrics
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.environment
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.orchestration
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.resource
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.dryrun
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.code
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.file
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.autostarted_agent_manager
DEBUG    inmanta.server.agentmanager:agentmanager.py:835 Stopping all autostarted agents
DEBUG    inmanta.server.agentmanager:agentmanager.py:839 Expiring all sessions
DEBUG    inmanta.server.protocol:protocol.py:630 Expired session with id c58c9284-be9f-11eb-a50e-005056b8e25e, last seen 0 seconds ago
DEBUG    inmanta.server.protocol:protocol.py:630 Expired session with id c58b67ce-be9f-11eb-a50e-005056b8e25e, last seen 0 seconds ago
DEBUG    inmanta.server.protocol:protocol.py:654 Heartbeat wait expired for jenkins-runner-5.ii.inmanta.com, returning. (long poll)
INFO     tornado.access:web.py:2243 200 POST /api/v1/heartbeat (127.0.0.1) 208.40ms
DEBUG    inmanta.server.protocol:protocol.py:654 Heartbeat wait expired for jenkins-runner-5.ii.inmanta.com, returning. (long poll)
INFO     tornado.access:web.py:2243 200 POST /api/v1/heartbeat (127.0.0.1) 240.72ms
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.server
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.compiler
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.agentmanager
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.session
DEBUG    inmanta.server.protocol:protocol.py:187 Pre Stopping core.database
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.transport
DEBUG    inmanta.server.agentmanager:agentmanager.py:425 expiring session c58c9284-be9f-11eb-a50e-005056b8e25e
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.project
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.parameters
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.metrics
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.environment
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.orchestration
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.resource
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.dryrun
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.code
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.file
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.autostarted_agent_manager
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.server
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.compiler
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.agentmanager
WARNING  inmanta.util:util.py:311 Task <Task cancelled coro=<AgentManager._log_session_creation_to_db() done, defined at /home/jenkins/workspace/core_inmanta-core_iso3/project/inmanta-core/.tox/py36/lib/python3.6/site-packages/inmanta/server/agentmanager.py:395>> was cancelled.
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.session
DEBUG    inmanta.server.protocol:protocol.py:191 Stopping core.database
DEBUG    inmanta.data:__init__.py:2809 Disconnecting data classes
INFO     conftest:conftest.py:528 Server clean up done
- generated xml file: /home/jenkins/workspace/core_inmanta-core_iso3/project/inmanta-core/junit-py36.xml -
sanderr commented 2 years ago

I guess this can be closed?