This is something to augment for debugging when this fails like it has happend recently, so now, when there's errors or warnings we should see something like this:
> assert re.findall(r'kytos.*?(error|exception)(.*)?', f.read(), re.I) == []
E assert [('ERROR', ' ...","name":"N')] == []
E Left contains one more item: ('ERROR', ' main:167: Failed to push flows on 00:00:00:00:00:00:00:01, error: {"code":404,"description":"switch is disabled.","name":"N')
E Use -v to get the full diff
Before it used to be like this:
def test_start_kytos_without_errors(self):
with open('/var/log/syslog', "r") as f:
> assert re.findall('kytos.*(error|exception)', f.read(), re.I) == []
E AssertionError: assert ['Error', 'Error'] == []
E Left contains 2 more items, first extra item: 'Error'
E Use -v to get the full diff
I tried it out with this sample here:
Jan 14 17:18:13 3325b525c0b9 kytos.napps.kytos/of_core:INFO main:176: Connection ('127.0.0.1', 53150), Switch 00:00:00:00:00:00:00:03: OPENFLOW HANDSHAKE COMPLETE
Jan 14 17:18:13 3325b525c0b9 kytos.napps.kytos/of_core:INFO main:176: Connection ('127.0.0.1', 53152), Switch 00:00:00:00:00:00:00:02: OPENFLOW HANDSHAKE COMPLETE
Jan 14 17:18:13 3325b525c0b9 kytos.napps.kytos/of_core:INFO main:176: Connection ('127.0.0.1', 53148), Switch 00:00:00:00:00:00:00:01: OPENFLOW HANDSHAKE COMPLETE
Jan 14 17:18:25 3325b525c0b9 kytos.napps.kytos/topology:INFO main:264: Storing administrative state from switch 00:00:00:00:00:00:00:01 to enabled.
Jan 14 17:18:25 3325b525c0b9 kytos.napps.kytos/topology:INFO storehouse:124: Network administrative status saved in kytos.topology.status.b4d48820809c4b52b193f68826e35ae8
Jan 14 17:18:25 3325b525c0b9 werkzeug:INFO _internal:113: 127.0.0.1 - - [14/Jan/2022 17:18:25] "#033[37mPOST /api/kytos/topology/v3/switches/00:00:00:00:00:00:00:01/enable HTTP/1.1#033
[0m" 201 -
Jan 14 17:18:25 3325b525c0b9 kytos.napps.kytos/topology:INFO main:278: Storing administrative state from switch 00:00:00:00:00:00:00:01 to disabled.
Jan 14 17:18:25 3325b525c0b9 kytos.napps.kytos/flow_manager:INFO main:724: Send FlowMod from request dpid: 00:00:00:00:00:00:00:01, command: add, force: False, flows_dict: {'flows': [{
'priority': 1000, 'table_id': 0, 'cookie': 12321848580485677057, 'match': {'dl_type': 35020, 'dl_vlan': 3799}, 'actions': [{'action_type': 'output', 'port': 4294967293}]}]}
Jan 14 17:18:25 3325b525c0b9 werkzeug:INFO _internal:113: 127.0.0.1 - - [14/Jan/2022 17:18:25] "#033[33mPOST /api/kytos/flow_manager/v2/flows/00:00:00:00:00:00:00:01 HTTP/1.1#033[0m" 4
04 -
Jan 14 17:18:25 3325b525c0b9 kytos.napps.kytos/of_lldp:ERROR main:167: Failed to push flows on 00:00:00:00:00:00:00:01, error: {"code":404,"description":"switch is disabled.","name":"N
ot Found"}#012, status: 404, data: {'flows': [{'priority': 1000, 'table_id': 0, 'cookie': 12321848580485677057, 'match': {'dl_type': <EtherType.LLDP: 35020>, 'dl_vlan': 3799}, 'actions'
: [{'action_type': 'output', 'port': <PortNo.OFPP_CONTROLLER: 4294967293>}]}]}
Jan 14 17:18:25 3325b525c0b9 kytos.napps.kytos/topology:INFO storehouse:124: Network administrative status saved in kytos.topology.status.b4d48820809c4b52b193f68826e35ae8
Jan 14 17:18:25 3325b525c0b9 werkzeug:INFO _internal:113: 127.0.0.1 - - [14/Jan/2022 17:18:25] "#033[37mPOST /api/kytos/topology/v3/switches/00:00:00:00:00:00:00:01/disable HTTP/1.1#03
3[0m" 201 -
Jan 14 17:18:25 3325b525c0b9 kytos.core.controller:INFO kytosd:124: Stopping Kytos controller...
Jan 14 17:18:25 3325b525c0b9 kytos.napps.kytos/flow_manager:INFO main:724: Send FlowMod from request dpid: 00:00:00:00:00:00:00:01, command: delete, force: False, flows_dict: {'flows':
[{'priority': 1000, 'table_id': 0, 'cookie': 12321848580485677057, 'cookie_mask': 18446744073709551615, 'match': {'dl_type': 35020, 'dl_vlan': 3799}, 'actions': [{'action_type': 'outpu
t', 'port': 4294967293}]}]}
Jan 14 17:18:25 3325b525c0b9 kytos.core.controller:INFO controller:407: Stopping Kytos
Jan 14 17:18:25 3325b525c0b9 werkzeug:INFO _internal:113: 127.0.0.1 - - [14/Jan/2022 17:18:25] "#033[37mDELETE /api/kytos/flow_manager/v2/flows/00:00:00:00:00:00:00:01 HTTP/1.1#033[0m"
202 -
Jan 14 17:18:25 3325b525c0b9 kytos.core.buffers:INFO buffers:161: Stop signal received by Kytos buffers.
Jan 14 17:18:25 3325b525c0b9 kytos.core.buffers:INFO buffers:162: Sending KytosShutdownEvent to all apps.
Jan 14 17:18:25 3325b525c0b9 kytos.core.buffers:INFO buffers:49: [buffer: raw_event] Stop mode enabled. Rejecting new events.
Jan 14 17:18:25 3325b525c0b9 kytos.core.buffers:INFO buffers:49: [buffer: msg_in_event] Stop mode enabled. Rejecting new events.
Jan 14 17:18:25 3325b525c0b9 kytos.core.buffers:INFO buffers:49: [buffer: msg_out_event] Stop mode enabled. Rejecting new events.
Jan 14 17:18:25 3325b525c0b9 kytos.core.buffers:INFO buffers:49: [buffer: app_event] Stop mode enabled. Rejecting new events.
Jan 14 17:18:25 3325b525c0b9 werkzeug:INFO _internal:113: 127.0.0.1 - - [14/Jan/2022 17:18:25] "#033[37mGET /api/kytos/core/_shutdown HTTP/1.1#033[0m" 200 -
Jan 14 17:18:25 3325b525c0b9 kytos.core.napps.napp_dir_listener:INFO napp_dir_listener:45: NAppDirListener Stopped...
Jan 14 17:18:25 3325b525c0b9 kytos.core.controller:INFO controller:413: Stopping threadpool: <concurrent.futures.thread.ThreadPoolExecutor object at 0x7f61133e5610>
Jan 14 17:18:25 3325b525c0b9 kytos.core.controller:INFO controller:415: Stopping threadpool: <concurrent.futures.thread.ThreadPoolExecutor object at 0x7f611467cd30>
Jan 14 17:18:26 3325b525c0b9 kytos.core.controller:INFO controller:893: Shutting down NApp kytos/pathfinder...
This is something to augment for debugging when this fails like it has happend recently, so now, when there's errors or warnings we should see something like this:
Before it used to be like this:
I tried it out with this sample here: