OPNsense Forum

Archive => 22.1 Legacy Series => Topic started by: ducky87 on January 31, 2022, 09:45:01 am

Title: WAN Interface lost connection after "reset interface" (pppoe)
Post by: ducky87 on January 31, 2022, 09:45:01 am: Hi,

since the upgrade from 21.7 to 22.1 I have the following problem:

A cronjob with "reset Interface" for the interface WAN starts every day at 3am (for the ISP timeout after 24h).

Since the upgrade the pppoe connection goes down. I have to start the connection for WAN manually (choose up in the Interface overview) after the cronjob. Connection is pppoe.
At 21.7 the connection connects after the "reset interface" command.

Thank y for help.
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: birdy on January 31, 2022, 12:31:23 pm: Same over here (Germany/1und1-DSL/PPPoE)

Every night reset (reconfigure) via Cron job worked in 21.7. Now in 22.1 after the cronjob did run the interface (PPPoE) is down, have to reconnect manually.
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: franco on January 31, 2022, 02:01:03 pm: Doesn't the cron job just do what the restart does?

Any system logs to share around the time of the cron job?

Cheers,
Franco
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: birdy on January 31, 2022, 04:43:01 pm: Cronjob runs at 3:07.

Code: [Select]
# DO NOT EDIT THIS FILE -- OPNsense auto-generated file # # User-defined crontab files can be loaded via /etc/cron.d # or /usr/local/etc/cron.d and follow the same format as # /etc/crontab, see the crontab(5) manual page. SHELL=/bin/sh PATH=/etc:/bin:/sbin:/usr/bin:/usr/sbin:/usr/local/bin:/usr/local/sbin #minute hour mday month wday command # Origin/Description: cron/Zwangstrennung 7 3 * * * /usr/local/sbin/configctl interface reconfigure wan
Manual reconnected the interface at 7:56.

Code: [Select]
2022-01-31T08:01:00 Informational configd.py message d3e453c1-a10b-4956-ac15-4a827d522058 [syslog.archive] returned OK 2022-01-31T08:01:00 Notice configd.py [d3e453c1-a10b-4956-ac15-4a827d522058] Archive syslog files 2022-01-31T07:57:14 Debug configd.py OPNsense/Cron generated //var/cron/tabs/nobody 2022-01-31T07:57:14 Notice configd.py generate template container OPNsense/Cron 2022-01-31T07:57:14 Notice configd.py [febae469-1798-4443-8641-d551f0953bb1] generate template OPNsense/Cron 2022-01-31T07:57:14 Notice configd.py [52387dcc-39fb-408a-943c-41dbd81edf7a] restarting cron 2022-01-31T07:57:13 Notice configd.py [4bb146a5-61bf-4b22-bdec-013b8c09fb9a] trigger config changed event 2022-01-31T07:57:05 Informational configd.py message 16da3e05-7a42-465b-ae24-0b76cebda3be [unbound.start] returned OK 2022-01-31T07:56:59 Informational configd.py message f27bd540-f967-4fc8-84ad-637ab69f2e2f [unbound.start] returned OK 2022-01-31T07:56:59 Notice configd.py [7ee5693c-f72f-4bba-a8ca-4d34135d5ce6] update IPv6 prefixes 2022-01-31T07:56:59 Notice configd.py [f27bd540-f967-4fc8-84ad-637ab69f2e2f] Starting Unbound 2022-01-31T07:56:59 Informational configd.py message c80fbc64-5b7c-46b6-8565-2de105b4b77d [interface.newipv6] returned OK 2022-01-31T07:56:59 Notice configd.py [16da3e05-7a42-465b-ae24-0b76cebda3be] Starting Unbound 2022-01-31T07:56:59 Debug configd.py OPNsense/Unbound/* generated //usr/local/etc/unbound_dhcpd.conf 2022-01-31T07:56:59 Debug configd.py OPNsense/Unbound/* generated //var/unbound/root.hints 2022-01-31T07:56:59 Debug configd.py OPNsense/Unbound/* generated //usr/local/etc/unbound.opnsense.d/miscellaneous.conf 2022-01-31T07:56:59 Debug configd.py OPNsense/Unbound/* generated //usr/local/etc/unbound.opnsense.d/dot.conf 2022-01-31T07:56:59 Debug configd.py OPNsense/Unbound/* generated //tmp/unbound-blocklists.conf 2022-01-31T07:56:59 Notice configd.py generate template container OPNsense/Unbound/core 2022-01-31T07:56:59 Notice configd.py [2e87a5dd-a9b2-41de-80ac-bd97aa1faf4a] generate template OPNsense/Unbound/* 2022-01-31T07:56:59 Debug configd.py OPNsense/Unbound/* generated //usr/local/etc/unbound_dhcpd.conf 2022-01-31T07:56:59 Debug configd.py OPNsense/Unbound/* generated //var/unbound/root.hints 2022-01-31T07:56:59 Debug configd.py OPNsense/Unbound/* generated //usr/local/etc/unbound.opnsense.d/miscellaneous.conf 2022-01-31T07:56:59 Debug configd.py OPNsense/Unbound/* generated //usr/local/etc/unbound.opnsense.d/dot.conf 2022-01-31T07:56:59 Debug configd.py OPNsense/Unbound/* generated //tmp/unbound-blocklists.conf 2022-01-31T07:56:59 Notice configd.py generate template container OPNsense/Unbound/core 2022-01-31T07:56:59 Notice configd.py [c76c8b22-69b8-4fed-a23f-78839b7dcaac] generate template OPNsense/Unbound/* 2022-01-31T07:56:59 Notice configd.py [9bd786eb-3a01-4df3-bb3f-5369d58deef1] Request vmstat interrupt counters 2022-01-31T07:56:59 Notice configd.py [21e62d99-1a95-4798-9197-6429c636ae40] request pfctl byte/packet counters 2022-01-31T07:56:58 Notice configd.py [4521eb6a-45e4-45a2-856b-7f0d6cc0f461] Unbound cache dump 2022-01-31T07:56:58 Notice configd.py [7ffcf6f1-ee85-48c9-b451-a2651b5ce17c] Unbound cache dump 2022-01-31T07:56:58 Notice configd.py [979f35a4-c977-4abc-9739-8077d7fe15b4] request mac table 2022-01-31T07:56:49 Informational configd.py message b91103fd-b273-4340-b203-4f54c9cb93eb [filter.refresh_aliases] returned {"status": "ok"} 2022-01-31T07:56:49 Notice configd.py [b91103fd-b273-4340-b203-4f54c9cb93eb] refresh url table aliases 2022-01-31T07:56:49 Debug configd.py OPNsense/Filter generated //usr/local/etc/filter_geoip.conf 2022-01-31T07:56:49 Debug configd.py OPNsense/Filter generated //usr/local/etc/filter_tables.conf 2022-01-31T07:56:49 Notice configd.py generate template container OPNsense/Filter 2022-01-31T07:56:49 Notice configd.py [4a9d044a-dd52-4fb0-aad5-cf89f76cd036] generate template OPNsense/Filter 2022-01-31T07:56:48 Notice configd.py [ba7b9ff8-02ed-4f25-b3b6-2fb92cd64093] request pf current overall table record count and table-entries limit 2022-01-31T07:56:48 Informational configd.py message e26c194d-9564-48f5-8557-06a3f5e897e8 [unbound.start] returned OK 2022-01-31T07:56:48 Notice configd.py [172ee4e6-4a77-4d44-884b-a093f13a19a1] update IPv6 prefixes 2022-01-31T07:56:48 Notice configd.py [c80fbc64-5b7c-46b6-8565-2de105b4b77d] New IPv6 on pppoe0 2022-01-31T07:56:47 Informational configd.py message cafa3509-2657-48ae-b391-100fd7c81842 [filter.refresh_aliases] returned {"status": "ok"} 2022-01-31T07:56:47 Notice configd.py [cafa3509-2657-48ae-b391-100fd7c81842] refresh url table aliases 2022-01-31T07:56:47 Debug configd.py OPNsense/Filter generated //usr/local/etc/filter_geoip.conf 2022-01-31T07:56:47 Debug configd.py OPNsense/Filter generated //usr/local/etc/filter_tables.conf 2022-01-31T07:56:46 Notice configd.py generate template container OPNsense/Filter 2022-01-31T07:56:46 Notice configd.py [c6bbd024-f545-4038-8895-22ca7216bf93] generate template OPNsense/Filter 2022-01-31T07:56:46 Notice configd.py [488075f8-0010-4244-91b2-d775dc4f60b3] updating dyndns wan 2022-01-31T07:56:46 Notice configd.py [e26c194d-9564-48f5-8557-06a3f5e897e8] Starting Unbound 2022-01-31T07:56:46 Debug configd.py OPNsense/Unbound/* generated //usr/local/etc/unbound_dhcpd.conf 2022-01-31T07:56:46 Debug configd.py OPNsense/Unbound/* generated //var/unbound/root.hints 2022-01-31T07:56:46 Debug configd.py OPNsense/Unbound/* generated //usr/local/etc/unbound.opnsense.d/miscellaneous.conf 2022-01-31T07:56:46 Debug configd.py OPNsense/Unbound/* generated //usr/local/etc/unbound.opnsense.d/dot.conf 2022-01-31T07:56:46 Debug configd.py OPNsense/Unbound/* generated //tmp/unbound-blocklists.conf 2022-01-31T07:56:46 Notice configd.py generate template container OPNsense/Unbound/core 2022-01-31T07:56:46 Notice configd.py [8480a8a1-4e4a-441d-9e5a-3a6c28ae784f] generate template OPNsense/Unbound/* 2022-01-31T07:56:46 Notice configd.py [3bece310-1acb-4324-a99d-829a02488a36] Unbound cache dump 2022-01-31T07:56:46 Notice configd.py [d7538405-f3ff-4a8e-9ade-df7207d89c76] request pf current overall table record count and table-entries limit 2022-01-31T07:56:46 Notice configd.py [c6d6608a-87f0-44ab-9bf6-6f24d3272df9] update IPv6 prefixes 2022-01-31T07:56:46 Informational configd.py message ea3763d0-f99d-4964-afdd-8a753f5b0d98 [interface.newipv6] returned OK 2022-01-31T07:56:44 Notice configd.py [ea3763d0-f99d-4964-afdd-8a753f5b0d98] New IPv6 on pppoe0 2022-01-31T07:56:44 Notice configd.py [c0809e7a-bac8-40b2-b0dc-a822498bfeb4] New IPv4 on pppoe0 2022-01-31T07:56:40 Notice configd.py [1d6a2bf6-0ec3-4f9f-b39a-9820fa557dba] Request vmstat interrupt counters 2022-01-31T07:56:40 Notice configd.py [43be2e78-cb72-4fb2-b152-a039b37f358a] request pfctl byte/packet counters 2022-01-31T07:56:40 Notice configd.py [2b94127f-bd4c-4ee3-bc7d-686c06b69d83] request mac table 2022-01-31T07:56:37 Notice configd.py [be4e5077-d4eb-4da3-a275-e97c93d57803] Retrieve firmware product info 2022-01-31T07:56:36 Notice configd.py [b2b7aa76-ec6d-47e0-a223-2288e6f8afc9] request traffic stats 2022-01-31T07:56:36 Notice configd.py [58bf334a-2ab7-410f-bc23-d424d8c3eafc] list gateway status 2022-01-31T07:56:31 Notice configd.py [2781539b-043d-4139-bd63-e057a7f52c46] Retrieve firmware product info 2022-01-31T07:56:31 Notice configd.py [462b85ee-3ed4-489a-94dd-6e4bfb14fe3a] request traffic stats 2022-01-31T07:56:31 Notice configd.py [7b2a1150-130f-459d-bd94-70d46280f131] request traffic stats 2022-01-31T07:56:31 Notice configd.py [1cdc55fe-7dbf-4742-b0a2-7dca9c0c4829] list gateway status 2022-01-31T07:45:26 Notice configd.py [8d838f57-451b-457d-bcca-1528dcc46378] update IPv6 prefixes 2022-01-31T07:45:26 Notice configd.py [8ead1b87-fd00-4e6f-bc24-d74b90568c36] update IPv6 prefixes 2022-01-31T07:40:59 Notice configd.py [587ef194-25ef-40f6-b1de-858b9578e942] update IPv6 prefixes 2022-01-31T07:40:59 Notice configd.py [64f04aad-67ff-46be-b506-899a88b3346d] update IPv6 prefixes 2022-01-31T07:27:53 Notice configd.py [267bbb28-953c-4f6f-84f6-4dd8c069d361] update IPv6 prefixes 2022-01-31T07:27:53 Notice configd.py [a70636b4-5693-46b1-9299-558dffcb427b] update IPv6 prefixes 2022-01-31T07:26:49 Notice configd.py [1f79eb9e-9e45-40b7-97a1-e23d3da37b27] update IPv6 prefixes 2022-01-31T07:26:49 Notice configd.py [dca5b271-6c58-4f94-96e1-d57e0e021a70] update IPv6 prefixes 2022-01-31T07:19:43 Notice configd.py [82d753ba-7d93-4022-8026-1437a1bd4e75] update IPv6 prefixes 2022-01-31T07:19:43 Notice configd.py [c1bd3659-bd39-49fe-8ab0-e9bcb3f49229] update IPv6 prefixes 2022-01-31T07:18:18 Notice configd.py [e4c9d81d-b960-4ac6-bf48-8bdeabd7db9e] update IPv6 prefixes 2022-01-31T07:18:18 Notice configd.py [85097c5c-a38e-4c12-bcc8-0ecee7c2c410] update IPv6 prefixes 2022-01-31T07:07:56 Notice configd.py [3a9cc7a5-87c5-4415-8232-faf886ed3439] update IPv6 prefixes 2022-01-31T07:07:56 Notice configd.py [64a673d4-23f7-4f9b-9f52-a2a5fd5765e9] update IPv6 prefixes 2022-01-31T07:01:00 Informational configd.py message 80aaa3a4-726c-4537-bd43-c8860b763557 [syslog.archive] returned OK 2022-01-31T07:01:00 Notice configd.py [80aaa3a4-726c-4537-bd43-c8860b763557] Archive syslog files 2022-01-31T06:50:23 Notice configd.py [9fceae87-d010-4de1-b45f-74e15f08679c] update IPv6 prefixes 2022-01-31T06:50:23 Notice configd.py [0f75984a-fb97-472d-ae71-3281bc1eab95] update IPv6 prefixes 2022-01-31T06:49:19 Notice configd.py [cceddbe7-64e2-47fe-80fd-4158afe398ef] update IPv6 prefixes 2022-01-31T06:49:19 Notice configd.py [6b12a779-9924-4ca3-957a-2eb9b191b289] update IPv6 prefixes 2022-01-31T06:38:19 Notice configd.py [8579752c-1fb5-4ba1-a8cf-35b1401b3ff7] update IPv6 prefixes 2022-01-31T06:38:19 Notice configd.py [37d11f7d-f271-40bc-a384-cc3dde1ed0ad] update IPv6 prefixes 2022-01-31T06:35:49 Notice configd.py [f13d2861-b280-49dc-95be-1381106c94d4] update IPv6 prefixes 2022-01-31T06:35:49 Notice configd.py [0420a3bf-800d-443d-a595-4806c657b0e4] update IPv6 prefixes 2022-01-31T06:30:26 Notice configd.py [7b69e673-a2f0-4e75-a9ec-8eb81a4ff4df] update IPv6 prefixes 2022-01-31T06:30:26 Notice configd.py [3c677678-c2b8-4433-b55f-084339a7b8a5] update IPv6 prefixes 2022-01-31T06:20:13 Notice configd.py [15c0a5eb-d858-40b2-be84-de6557d5a6dc] update IPv6 prefixes 2022-01-31T06:20:13 Notice configd.py [ff2d8d9d-3a21-40c8-b39e-c93d08f1ea58] update IPv6 prefixes 2022-01-31T06:12:53 Notice configd.py [6935de15-2593-41cc-a09c-fd6a0307263f] update IPv6 prefixes 2022-01-31T06:12:53 Notice configd.py [f389b164-3948-4e40-ba9d-77036ddc01c1] update IPv6 prefixes 2022-01-31T06:11:49 Notice configd.py [f204b402-46ce-4f1a-8685-f4e38417cfc2] update IPv6 prefixes 2022-01-31T06:11:49 Notice configd.py [54d77503-2e48-4173-a1be-755e709a81d9] update IPv6 prefixes 2022-01-31T06:01:00 Informational configd.py message 6b492815-3429-4c11-bd67-fe14d11fc88c [syslog.archive] returned OK 2022-01-31T06:01:00 Notice configd.py [6b492815-3429-4c11-bd67-fe14d11fc88c] Archive syslog files 2022-01-31T05:52:56 Notice configd.py [c89489ce-3d22-40e6-913b-82ee4a1681a6] update IPv6 prefixes 2022-01-31T05:52:56 Notice configd.py [2df96d54-56ba-45a0-ae17-3ca9783100c1] update IPv6 prefixes 2022-01-31T05:38:32 Notice configd.py [92abdb90-2158-4fd9-8d5d-7073d0840bda] update IPv6 prefixes 2022-01-31T05:38:32 Notice configd.py [2a90e1bd-97e5-4682-9a65-881837db933f] update IPv6 prefixes 2022-01-31T05:36:09 Notice configd.py [894d3024-1497-4bda-b161-d12e1be3ad1d] update IPv6 prefixes 2022-01-31T05:36:09 Notice configd.py [5a4558c0-3e28-4bff-9cec-c2a5c22ffd3a] update IPv6 prefixes 2022-01-31T05:35:23 Notice configd.py [373a8d73-b5b5-46b3-8216-77b9b644ae13] update IPv6 prefixes 2022-01-31T05:35:23 Notice configd.py [38b6929c-764b-443d-82e3-98c8b4975112] update IPv6 prefixes 2022-01-31T05:34:19 Notice configd.py [05398d36-c474-48e1-935f-98cbdc9a924e] update IPv6 prefixes 2022-01-31T05:34:19 Notice configd.py [63bc9573-052b-4704-af60-991800ed0b2f] update IPv6 prefixes 2022-01-31T05:24:53 Notice configd.py [025082a8-5df7-4b10-aac1-1b1fe16a6d0d] update IPv6 prefixes 2022-01-31T05:24:53 Notice configd.py [2768b334-930d-4f5c-82a0-c463fe98c540] update IPv6 prefixes 2022-01-31T05:15:27 Notice configd.py [eea2871f-65ac-4112-aa05-448e2a3ed786] update IPv6 prefixes 2022-01-31T05:15:27 Notice configd.py [50efe029-b3d3-443c-b6f5-8601778306a0] update IPv6 prefixes 2022-01-31T05:01:00 Informational configd.py message 76f5fcfd-e284-4876-8b27-2870d00778dc [syslog.archive] returned OK 2022-01-31T05:01:00 Notice configd.py [76f5fcfd-e284-4876-8b27-2870d00778dc] Archive syslog files 2022-01-31T04:57:53 Notice configd.py [7e2ba702-e87d-448e-b5f1-7aede4965df1] update IPv6 prefixes 2022-01-31T04:57:53 Notice configd.py [03ba3143-b631-4069-ab21-261b03a0a372] update IPv6 prefixes 2022-01-31T04:56:49 Notice configd.py [f455e11a-6747-4d9a-8ccc-74f336e3db8b] update IPv6 prefixes 2022-01-31T04:56:49 Notice configd.py [a5551358-60c1-4f51-8c76-c4453f09ebf7] update IPv6 prefixes 2022-01-31T04:38:49 Notice configd.py [05845033-2ba2-4762-8a89-296c05844cb4] update IPv6 prefixes 2022-01-31T04:38:49 Notice configd.py [70416bfc-43d3-40f3-80ea-9f679a49b65e] update IPv6 prefixes 2022-01-31T04:37:57 Notice configd.py [829fd3d5-5a58-488a-aca8-59f748a625a8] update IPv6 prefixes 2022-01-31T04:37:57 Notice configd.py [09372e95-4de6-47f3-8a62-998c824c32da] update IPv6 prefixes 2022-01-31T04:25:23 Notice configd.py [6aa16414-17b1-4991-980e-199b84747af2] update IPv6 prefixes 2022-01-31T04:25:23 Notice configd.py [b5132b2b-0509-45ec-a541-87f89b70b812] update IPv6 prefixes 2022-01-31T04:24:02 Informational configd.py message e93c328a-9235-4ccd-965e-b46f35fd1bb6 [firmware.changelog] returned Error (1) 2022-01-31T04:24:02 Error configd.py [e93c328a-9235-4ccd-965e-b46f35fd1bb6] returned exit status 1 2022-01-31T04:20:23 Notice configd.py [de627a5c-6da5-406f-ac76-84597fe1f050] update IPv6 prefixes 2022-01-31T04:20:23 Notice configd.py [bb5a3738-4521-4863-a6bb-bd5c37ad223a] update IPv6 prefixes 2022-01-31T04:19:19 Notice configd.py [b6e41e3d-d021-4eaa-b59e-a7f33417e44d] update IPv6 prefixes 2022-01-31T04:19:19 Notice configd.py [153680e0-3787-449c-b598-185fd15ce9f8] update IPv6 prefixes 2022-01-31T04:03:48 Notice configd.py [634cc5e1-37f0-40c9-8f8b-9f942695d6aa] update IPv6 prefixes 2022-01-31T04:01:00 Informational configd.py message 781fab7e-99fc-44f0-b523-338a7006fbe1 [syslog.archive] returned OK 2022-01-31T04:01:00 Notice configd.py [781fab7e-99fc-44f0-b523-338a7006fbe1] Archive syslog files 2022-01-31T04:00:27 Notice configd.py [c4ffcf16-e70f-4b8b-a1b4-dfdc0cf009d7] update IPv6 prefixes 2022-01-31T03:42:53 Notice configd.py [d788ad4b-f7fa-4cee-be98-1b7b99a7873c] update IPv6 prefixes 2022-01-31T03:41:49 Notice configd.py [f970b5a4-2cd0-481c-9679-6ca996abae30] update IPv6 prefixes 2022-01-31T03:37:49 Notice configd.py [f819a87c-f515-45aa-9912-0fbae35a0e8a] update IPv6 prefixes 2022-01-31T03:22:03 Notice configd.py [12e38999-4dcd-4f8c-97d0-34f475d26efd] update IPv6 prefixes 2022-01-31T03:07:48 Informational configd.py message 7cbaf8db-af9f-4f86-9e27-2162ca9bce5a [unbound.start] returned OK 2022-01-31T03:07:46 Informational configd.py message fd9a627d-7939-4613-89da-d09c895ee0ce [dns.reload] returned OK 2022-01-31T03:07:46 Notice configd.py [fd9a627d-7939-4613-89da-d09c895ee0ce] Rewriting resolv.conf 2022-01-31T03:07:02 Informational configd.py message 490631ea-1c96-4667-b15c-a8dca3fc134f [interface.reconfigure] returned OK 2022-01-31T03:07:01 Notice configd.py [81286543-5bcc-4a9b-ba2d-c04f191ce990] updating dyndns wan 2022-01-31T03:07:00 Notice configd.py [7cbaf8db-af9f-4f86-9e27-2162ca9bce5a] Starting Unbound 2022-01-31T03:07:00 Debug configd.py OPNsense/Unbound/* generated //usr/local/etc/unbound_dhcpd.conf 2022-01-31T03:07:00 Debug configd.py OPNsense/Unbound/* generated //var/unbound/root.hints 2022-01-31T03:07:00 Debug configd.py OPNsense/Unbound/* generated //usr/local/etc/unbound.opnsense.d/miscellaneous.conf 2022-01-31T03:07:00 Debug configd.py OPNsense/Unbound/* generated //usr/local/etc/unbound.opnsense.d/dot.conf 2022-01-31T03:07:00 Debug configd.py OPNsense/Unbound/* generated //tmp/unbound-blocklists.conf 2022-01-31T03:07:00 Notice configd.py generate template container OPNsense/Unbound/core 2022-01-31T03:07:00 Notice configd.py [cd812974-2113-4eb3-9f24-7f95e669f174] generate template OPNsense/Unbound/* 2022-01-31T03:07:00 Notice configd.py [0428a023-0230-4983-8828-9f34c301fce4] Unbound cache dump 2022-01-31T03:07:00 Notice configd.py [da295b07-60cf-4af9-87da-c59094da250e] update IPv6 prefixes 2022-01-31T03:07:00 Informational configd.py message c5cbcc45-e128-4181-a199-67d58ff3e079 [dns.reload] returned OK 2022-01-31T03:07:00 Notice configd.py [c5cbcc45-e128-4181-a199-67d58ff3e079] Rewriting resolv.conf 2022-01-31T03:07:00 Notice configd.py [490631ea-1c96-4667-b15c-a8dca3fc134f] Configuring interface wan
BTW: OPNsense runs virtual on Proxmox.
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: birdy on January 31, 2022, 09:54:38 pm: Did some testing.

Running

Code: [Select]
configctl interface reconfigure wan
disconnects the interface. Running it again reconnects the interface and it is working again.

As a workaround I configured the cronjob to run at 3:07 and 3:09.
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: Shcshc on January 31, 2022, 10:39:06 pm: I have the same problem

Gesendet von iPad mit Tapatalk Pro
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: lhfdjklshfjkdlas on February 02, 2022, 08:04:26 am: I noticed the same issue with PPPOE and periodic interface reset.
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: franco on February 02, 2022, 09:11:33 am: Not sure how to reproduce this yet but the twice does the trick would indicate the issue is rather simple to fix.

Is Unbound running in these cases when it broke? Is the PPPoE daemon running?

# pgrep unbound
# pgrep mpd5

All help is appreciated.

Cheers,
Franco
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: chris42 on February 02, 2022, 10:18:43 am: Hi there,

had this in the morning as well, after upgrading yesterday. Sadly did a restart, so logs are gone.

Checking for unbound and mdp5 now:
unbound is running, mdp5 not

Cheers
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: franco on February 02, 2022, 10:21:57 am: Sorry typo, should have been:

# pgrep mpd5

Cheers,
Franco
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: chris42 on February 02, 2022, 10:31:06 am: mpd5 läuft auch.

Würde ein ppp log helfen, wenn ich den cron für die Trennung mal eben nach vorne ziehe?
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: chris42 on February 02, 2022, 10:55:01 am: So just did pull the reconnect forward. This is the part of the reconnect:
Code: [Select]
2022-02-02T10:40:33 Informational ppp process 30190 terminated 2022-02-02T10:40:33 Informational ppp [wan_link0] Link: Shutdown 2022-02-02T10:40:33 Informational ppp [wan] Bundle: Shutdown 2022-02-02T10:40:31 Informational ppp [wan_link0] LCP: Close event 2022-02-02T10:40:31 Informational ppp [wan_link0] Link: CLOSE event 2022-02-02T10:40:31 Informational ppp [wan_link0] LCP: state change Closing --> Initial 2022-02-02T10:40:31 Informational ppp [wan_link0] LCP: LayerFinish 2022-02-02T10:40:31 Informational ppp [wan_link0] LCP: Down event 2022-02-02T10:40:31 Informational ppp [wan_link0] LCP: state change Stopping --> Closing 2022-02-02T10:40:31 Informational ppp [wan_link0] LCP: Close event 2022-02-02T10:40:31 Informational ppp [wan_link0] Link: giving up after 0 reconnection attempts 2022-02-02T10:40:31 Informational ppp [wan_link0] Link: DOWN event 2022-02-02T10:40:31 Informational ppp [wan_link0] PPPoE: connection closed 2022-02-02T10:40:31 Informational ppp [wan_link0] LCP: LayerDown 2022-02-02T10:40:31 Informational ppp [wan_link0] LCP: SendTerminateAck #4 2022-02-02T10:40:31 Informational ppp [wan] IPV6CP: state change Closed --> Initial 2022-02-02T10:40:31 Informational ppp [wan] IPV6CP: Down event 2022-02-02T10:40:31 Informational ppp [wan] IPCP: state change Closed --> Initial 2022-02-02T10:40:31 Informational ppp [wan] IPCP: Down event 2022-02-02T10:40:31 Informational ppp [wan] IPV6CP: Close event 2022-02-02T10:40:31 Informational ppp [wan] IPCP: Close event 2022-02-02T10:40:31 Informational ppp [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps 2022-02-02T10:40:31 Informational ppp [wan_link0] Link: Leave bundle "wan" 2022-02-02T10:40:31 Informational ppp [wan_link0] LCP: state change Opened --> Stopping 2022-02-02T10:40:31 Informational ppp [wan_link0] LCP: rec'd Terminate Request #3 (Opened) 2022-02-02T10:40:31 Informational ppp [wan] Bundle: closing link "wan_link0"... 2022-02-02T10:40:31 Informational ppp [wan] Bundle: No NCPs left. Closing links... 2022-02-02T10:40:31 Informational ppp [wan] IPV6CP: LayerFinish 2022-02-02T10:40:31 Informational ppp [wan] IPV6CP: state change Closing --> Closed 2022-02-02T10:40:31 Informational ppp [wan] IPV6CP: rec'd Terminate Ack #2 (Closing) 2022-02-02T10:40:31 Informational ppp [wan] IPCP: LayerFinish 2022-02-02T10:40:31 Informational ppp [wan] IPCP: state change Closing --> Closed 2022-02-02T10:40:31 Informational ppp [wan] IPCP: rec'd Terminate Ack #4 (Closing) 2022-02-02T10:40:31 Informational ppp [wan] IPCP: SendTerminateReq #5 2022-02-02T10:40:31 Informational ppp [wan] IPV6CP: SendTerminateReq #3 2022-02-02T10:40:31 Informational ppp [wan] IFACE: Rename interface pppoe1 to pppoe1 2022-02-02T10:40:31 Informational ppp [wan] IFACE: Down event 2022-02-02T10:40:31 Informational ppp can't lock /var/run/pppoe_wan.pid after 30 attempts 2022-02-02T10:40:30 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:29 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:28 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:27 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:26 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:25 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:24 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:23 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:22 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:21 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:20 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:19 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:18 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:17 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:16 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:15 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:14 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:13 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:12 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:11 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:10 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:08 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:07 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:06 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:05 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:04 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:03 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:02 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:01 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:01 Informational ppp [wan] IPV6CP: LayerDown 2022-02-02T10:40:01 Informational ppp [wan] IPV6CP: SendTerminateReq #2 2022-02-02T10:40:01 Informational ppp [wan] IPV6CP: state change Opened --> Closing 2022-02-02T10:40:01 Informational ppp [wan] IPV6CP: Close event 2022-02-02T10:40:01 Informational ppp [wan] IFACE: Removing IPv4 address from pppoe1 failed: Can't assign requested address 2022-02-02T10:40:01 Informational ppp [wan] IFACE: Delete route 0.0.0.0/0 <IP> failed: No such process 2022-02-02T10:40:00 Informational ppp [wan] IPCP: LayerDown 2022-02-02T10:40:00 Informational ppp [wan] IPCP: SendTerminateReq #4 2022-02-02T10:40:00 Informational ppp [wan] IPCP: state change Opened --> Closing 2022-02-02T10:40:00 Informational ppp [wan] IPCP: Close event 2022-02-02T10:40:00 Informational ppp [wan] IFACE: Close event 2022-02-02T10:40:00 Informational ppp caught fatal signal TERM 2022-02-02T10:40:00 Informational ppp waiting for process 30190 to die... 2022-02-02T10:40:00 Informational ppp process 44606 started, version 5.9 2022-02-02T10:40:00 Informational ppp 2022-02-02T10:40:00 Informational ppp Multi-link PPP daemon for FreeBSD
It then jut idles and you are offline. Using "configctl interface reconfigure wan" then reconnects:
Code: [Select]
2022-02-02T10:41:35 Informational ppp [wan] <IP> -> <IP> 2022-02-02T10:41:35 Informational ppp [wan] IPCP: LayerUp 2022-02-02T10:41:35 Informational ppp [wan] IPCP: state change Ack-Sent --> Opened 2022-02-02T10:41:35 Informational ppp [wan] IPADDR <IP> 2022-02-02T10:41:35 Informational ppp [wan] IPCP: rec'd Configure Ack #3 (Ack-Sent) 2022-02-02T10:41:35 Informational ppp [wan] IPADDR <IP> 2022-02-02T10:41:35 Informational ppp [wan] IPCP: SendConfigReq #3 2022-02-02T10:41:35 Informational ppp [wan] <IP> is OK 2022-02-02T10:41:35 Informational ppp [wan] IPADDR <IP> 2022-02-02T10:41:35 Informational ppp [wan] IPCP: rec'd Configure Nak #2 (Ack-Sent) 2022-02-02T10:41:35 Informational ppp [wan] IFACE: Rename interface ng0 to pppoe1 2022-02-02T10:41:35 Informational ppp [wan] IFACE: Up event 2022-02-02T10:41:35 Informational ppp [wan] <IPv6> -> <IPv6> 2022-02-02T10:41:35 Informational ppp [wan] IPV6CP: LayerUp 2022-02-02T10:41:35 Informational ppp [wan] IPV6CP: state change Ack-Sent --> Opened 2022-02-02T10:41:35 Informational ppp [wan] IPV6CP: rec'd Configure Ack #1 (Ack-Sent) 2022-02-02T10:41:35 Informational ppp [wan] IPADDR 0.0.0.0 2022-02-02T10:41:35 Informational ppp [wan] IPCP: SendConfigReq #2 2022-02-02T10:41:35 Informational ppp [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid 2022-02-02T10:41:35 Informational ppp [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent) 2022-02-02T10:41:35 Informational ppp [wan] IPV6CP: state change Req-Sent --> Ack-Sent 2022-02-02T10:41:35 Informational ppp [wan] IPV6CP: SendConfigAck #1 2022-02-02T10:41:35 Informational ppp [wan] IPV6CP: rec'd Configure Request #1 (Req-Sent) 2022-02-02T10:41:35 Informational ppp [wan] IPCP: state change Req-Sent --> Ack-Sent 2022-02-02T10:41:35 Informational ppp [wan] IPADDR <IP> 2022-02-02T10:41:35 Informational ppp [wan] IPCP: SendConfigAck #1 2022-02-02T10:41:35 Informational ppp [wan] <IP> is OK 2022-02-02T10:41:35 Informational ppp [wan] IPADDR <IP> 2022-02-02T10:41:35 Informational ppp [wan] IPCP: rec'd Configure Request #1 (Req-Sent) 2022-02-02T10:41:35 Informational ppp [wan] IPV6CP: SendConfigReq #1 2022-02-02T10:41:35 Informational ppp [wan] IPV6CP: state change Starting --> Req-Sent 2022-02-02T10:41:35 Informational ppp [wan] IPV6CP: Up event 2022-02-02T10:41:35 Informational ppp [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid 2022-02-02T10:41:35 Informational ppp [wan] IPADDR 0.0.0.0 2022-02-02T10:41:35 Informational ppp [wan] IPCP: SendConfigReq #1 2022-02-02T10:41:35 Informational ppp [wan] IPCP: state change Starting --> Req-Sent 2022-02-02T10:41:35 Informational ppp [wan] IPCP: Up event 2022-02-02T10:41:35 Informational ppp [wan] IPV6CP: LayerStart 2022-02-02T10:41:35 Informational ppp [wan] IPV6CP: state change Initial --> Starting 2022-02-02T10:41:35 Informational ppp [wan] IPV6CP: Open event 2022-02-02T10:41:35 Informational ppp [wan] IPCP: LayerStart 2022-02-02T10:41:35 Informational ppp [wan] IPCP: state change Initial --> Starting 2022-02-02T10:41:35 Informational ppp [wan] IPCP: Open event 2022-02-02T10:41:35 Informational ppp [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps 2022-02-02T10:41:35 Informational ppp [wan_link0] Link: Join bundle "wan" 2022-02-02T10:41:35 Informational ppp [wan_link0] Link: Matched action 'bundle "wan" ""' 2022-02-02T10:41:35 Informational ppp [wan_link0] LCP: authorization successful 2022-02-02T10:41:35 Informational ppp [wan_link0] MESG: [UI-SBR:55040,11136;UI-LINEID:1UND1.DEU.DTAG.CX6JK;] 2022-02-02T10:41:35 Informational ppp [wan_link0] PAP: rec'd ACK #1 len: 57 2022-02-02T10:41:35 Informational ppp [wan_link0] LCP: LayerUp 2022-02-02T10:41:35 Informational ppp [wan_link0] PAP: sending REQUEST #1 len: 52 2022-02-02T10:41:35 Informational ppp [wan_link0] PAP: using authname "****************" 2022-02-02T10:41:35 Informational ppp [wan_link0] LCP: auth: peer wants PAP, I want nothing 2022-02-02T10:41:35 Informational ppp [wan_link0] LCP: state change Ack-Rcvd --> Opened 2022-02-02T10:41:35 Informational ppp [wan_link0] MAGICNUM 0xdf05b818 2022-02-02T10:41:35 Informational ppp [wan_link0] AUTHPROTO PAP 2022-02-02T10:41:35 Informational ppp [wan_link0] MRU 1492 2022-02-02T10:41:35 Informational ppp [wan_link0] LCP: SendConfigAck #2 2022-02-02T10:41:35 Informational ppp [wan_link0] MAGICNUM 0xdf05b818 2022-02-02T10:41:35 Informational ppp [wan_link0] AUTHPROTO PAP 2022-02-02T10:41:35 Informational ppp [wan_link0] MRU 1492 2022-02-02T10:41:35 Informational ppp [wan_link0] LCP: rec'd Configure Request #2 (Ack-Rcvd) 2022-02-02T10:41:34 Informational ppp [wan_link0] LCP: state change Req-Sent --> Ack-Rcvd 2022-02-02T10:41:34 Informational ppp [wan_link0] MAGICNUM 0x5774ed80 2022-02-02T10:41:34 Informational ppp [wan_link0] MRU 1492 2022-02-02T10:41:34 Informational ppp [wan_link0] LCP: rec'd Configure Ack #3 (Req-Sent) 2022-02-02T10:41:34 Informational ppp [wan_link0] MAGICNUM 0x5774ed80 2022-02-02T10:41:34 Informational ppp [wan_link0] MRU 1492 2022-02-02T10:41:34 Informational ppp [wan_link0] LCP: SendConfigReq #3 2022-02-02T10:41:34 Informational ppp [wan_link0] LCP: state change Ack-Rcvd --> Req-Sent 2022-02-02T10:41:32 Informational ppp [wan_link0] LCP: state change Req-Sent --> Ack-Rcvd 2022-02-02T10:41:32 Informational ppp [wan_link0] MAGICNUM 0x5774ed80 2022-02-02T10:41:32 Informational ppp [wan_link0] MRU 1492 2022-02-02T10:41:32 Informational ppp [wan_link0] LCP: rec'd Configure Ack #2 (Req-Sent) 2022-02-02T10:41:32 Informational ppp [wan_link0] MAGICNUM 0x5774ed80 2022-02-02T10:41:32 Informational ppp [wan_link0] MRU 1492 2022-02-02T10:41:32 Informational ppp [wan_link0] LCP: SendConfigReq #2 2022-02-02T10:41:32 Informational ppp [wan_link0] PROTOCOMP 2022-02-02T10:41:32 Informational ppp [wan_link0] LCP: rec'd Configure Reject #1 (Req-Sent) 2022-02-02T10:41:32 Informational ppp [wan_link0] MAGICNUM 0x5774ed80 2022-02-02T10:41:32 Informational ppp [wan_link0] MRU 1492 2022-02-02T10:41:32 Informational ppp [wan_link0] PROTOCOMP 2022-02-02T10:41:32 Informational ppp [wan_link0] LCP: SendConfigReq #1 2022-02-02T10:41:32 Informational ppp [wan_link0] LCP: state change Starting --> Req-Sent 2022-02-02T10:41:32 Informational ppp [wan_link0] LCP: Up event 2022-02-02T10:41:32 Informational ppp [wan_link0] Link: UP event 2022-02-02T10:41:32 Informational ppp [wan_link0] PPPoE: connection successful 2022-02-02T10:41:32 Informational ppp PPPoE: rec'd ACNAME "************" 2022-02-02T10:41:32 Informational ppp [wan_link0] PPPoE: Connecting to '1und1' 2022-02-02T10:41:32 Informational ppp [wan_link0] LCP: LayerStart 2022-02-02T10:41:32 Informational ppp [wan_link0] LCP: state change Initial --> Starting 2022-02-02T10:41:32 Informational ppp [wan_link0] LCP: Open event 2022-02-02T10:41:32 Informational ppp [wan_link0] Link: OPEN event 2022-02-02T10:41:32 Informational ppp [wan] Bundle: Interface ng0 created 2022-02-02T10:41:32 Informational ppp web: web is not running 2022-02-02T10:41:32 Informational ppp process 16047 started, version 5.9 2022-02-02T10:41:32 Informational ppp 2022-02-02T10:41:32 Informational ppp Multi-link PPP daemon for FreeBSD
Hope I redacted personal information enough...
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: franco on February 02, 2022, 11:20:32 am: Thanks I think this is the problem:

> 2022-02-02T10:40:31 Informational ppp can't lock /var/run/pppoe_wan.pid after 30 attempts

So the old mpd5 is still running / not yielding to the reconnect likely because it wasn't being shut down yet.

Cheers,
Franco
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: franco on February 02, 2022, 11:46:29 am: https://github.com/opnsense/core/commit/3ccd2f0bdf07

Can you try this one?

# opnsense-patch 3ccd2f0bdf07

Cheers,
Franco
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: franco on February 02, 2022, 12:38:01 pm: Still missing the system log here. According to ancient commits for 2011 the -k mode is used for mpd5 which means it will take care of the existing process itself. Now that means the existing process won't yield and that's the biggest question then vs. using the SIGTERM in front of it. To my knowledge this has always worked before. Not sure if FreeBSD 13 is somewhat special in this regard.

Cheers,
Franco
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: chris42 on February 02, 2022, 01:28:33 pm: Quote from: franco on February 02, 2022, 12:38:01 pm
Still missing the system log here.

Any specifics to look out for in the system.log?

The patch seems to work. Below the log from the cron triggered disconnect.

Code: [Select]
2022-02-02T13:15:38 Informational ppp [wan] <IP> -> <IP> 2022-02-02T13:15:38 Informational ppp [wan] IPCP: LayerUp 2022-02-02T13:15:38 Informational ppp [wan] IPCP: state change Ack-Sent --> Opened 2022-02-02T13:15:38 Informational ppp [wan] IPADDR <IP> 2022-02-02T13:15:38 Informational ppp [wan] IPCP: rec'd Configure Ack #3 (Ack-Sent) 2022-02-02T13:15:38 Informational ppp [wan] IPADDR <IP> 2022-02-02T13:15:38 Informational ppp [wan] IPCP: SendConfigReq #3 2022-02-02T13:15:38 Informational ppp [wan] <IP> is OK 2022-02-02T13:15:38 Informational ppp [wan] IPADDR <IP> 2022-02-02T13:15:38 Informational ppp [wan] IPCP: rec'd Configure Nak #2 (Ack-Sent) 2022-02-02T13:15:38 Informational ppp [wan] IFACE: Rename interface ng0 to pppoe1 2022-02-02T13:15:38 Informational ppp [wan] IFACE: Up event 2022-02-02T13:15:37 Informational ppp [wan] <IPv6> -> <IPv6> 2022-02-02T13:15:37 Informational ppp [wan] IPV6CP: LayerUp 2022-02-02T13:15:37 Informational ppp [wan] IPV6CP: state change Ack-Sent --> Opened 2022-02-02T13:15:37 Informational ppp [wan] IPV6CP: rec'd Configure Ack #1 (Ack-Sent) 2022-02-02T13:15:37 Informational ppp [wan] IPADDR 0.0.0.0 2022-02-02T13:15:37 Informational ppp [wan] IPCP: SendConfigReq #2 2022-02-02T13:15:37 Informational ppp [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid 2022-02-02T13:15:37 Informational ppp [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent) 2022-02-02T13:15:37 Informational ppp [wan] IPV6CP: state change Req-Sent --> Ack-Sent 2022-02-02T13:15:37 Informational ppp [wan] IPV6CP: SendConfigAck #1 2022-02-02T13:15:37 Informational ppp [wan] IPV6CP: rec'd Configure Request #1 (Req-Sent) 2022-02-02T13:15:37 Informational ppp [wan] IPCP: state change Req-Sent --> Ack-Sent 2022-02-02T13:15:37 Informational ppp [wan] IPADDR <IP> 2022-02-02T13:15:37 Informational ppp [wan] IPCP: SendConfigAck #1 2022-02-02T13:15:37 Informational ppp [wan] <IP> is OK 2022-02-02T13:15:37 Informational ppp [wan] IPADDR <IP> 2022-02-02T13:15:37 Informational ppp [wan] IPCP: rec'd Configure Request #1 (Req-Sent) 2022-02-02T13:15:37 Informational ppp [wan] IPV6CP: SendConfigReq #1 2022-02-02T13:15:37 Informational ppp [wan] IPV6CP: state change Starting --> Req-Sent 2022-02-02T13:15:37 Informational ppp [wan] IPV6CP: Up event 2022-02-02T13:15:37 Informational ppp [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid 2022-02-02T13:15:37 Informational ppp [wan] IPADDR 0.0.0.0 2022-02-02T13:15:37 Informational ppp [wan] IPCP: SendConfigReq #1 2022-02-02T13:15:37 Informational ppp [wan] IPCP: state change Starting --> Req-Sent 2022-02-02T13:15:37 Informational ppp [wan] IPCP: Up event 2022-02-02T13:15:37 Informational ppp [wan] IPV6CP: LayerStart 2022-02-02T13:15:37 Informational ppp [wan] IPV6CP: state change Initial --> Starting 2022-02-02T13:15:37 Informational ppp [wan] IPV6CP: Open event 2022-02-02T13:15:37 Informational ppp [wan] IPCP: LayerStart 2022-02-02T13:15:37 Informational ppp [wan] IPCP: state change Initial --> Starting 2022-02-02T13:15:37 Informational ppp [wan] IPCP: Open event 2022-02-02T13:15:37 Informational ppp [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps 2022-02-02T13:15:37 Informational ppp [wan_link0] Link: Join bundle "wan" 2022-02-02T13:15:37 Informational ppp [wan_link0] Link: Matched action 'bundle "wan" ""' 2022-02-02T13:15:37 Informational ppp [wan_link0] LCP: authorization successful 2022-02-02T13:15:37 Informational ppp [wan_link0] MESG: [UI-SBR:55040,11136;UI-LINEID:1UND1.DEU.DTAG.CX6JK;] 2022-02-02T13:15:37 Informational ppp [wan_link0] PAP: rec'd ACK #1 len: 57 2022-02-02T13:15:37 Informational ppp [wan_link0] LCP: LayerUp 2022-02-02T13:15:37 Informational ppp [wan_link0] PAP: sending REQUEST #1 len: 52 2022-02-02T13:15:37 Informational ppp [wan_link0] PAP: using authname "***********" 2022-02-02T13:15:37 Informational ppp [wan_link0] LCP: auth: peer wants PAP, I want nothing 2022-02-02T13:15:37 Informational ppp [wan_link0] LCP: state change Ack-Rcvd --> Opened 2022-02-02T13:15:37 Informational ppp [wan_link0] MAGICNUM 0xb51e5e1f 2022-02-02T13:15:37 Informational ppp [wan_link0] AUTHPROTO PAP 2022-02-02T13:15:37 Informational ppp [wan_link0] MRU 1492 2022-02-02T13:15:37 Informational ppp [wan_link0] LCP: SendConfigAck #2 2022-02-02T13:15:37 Informational ppp [wan_link0] MAGICNUM 0xb51e5e1f 2022-02-02T13:15:37 Informational ppp [wan_link0] AUTHPROTO PAP 2022-02-02T13:15:37 Informational ppp [wan_link0] MRU 1492 2022-02-02T13:15:37 Informational ppp [wan_link0] LCP: rec'd Configure Request #2 (Ack-Rcvd) 2022-02-02T13:15:37 Informational ppp [wan_link0] LCP: state change Req-Sent --> Ack-Rcvd 2022-02-02T13:15:37 Informational ppp [wan_link0] MAGICNUM 0xe0085d10 2022-02-02T13:15:37 Informational ppp [wan_link0] MRU 1492 2022-02-02T13:15:37 Informational ppp [wan_link0] LCP: rec'd Configure Ack #3 (Req-Sent) 2022-02-02T13:15:37 Informational ppp [wan_link0] MAGICNUM 0xe0085d10 2022-02-02T13:15:37 Informational ppp [wan_link0] MRU 1492 2022-02-02T13:15:37 Informational ppp [wan_link0] LCP: SendConfigReq #3 2022-02-02T13:15:37 Informational ppp [wan_link0] LCP: state change Ack-Rcvd --> Req-Sent 2022-02-02T13:15:35 Informational ppp [wan_link0] LCP: state change Req-Sent --> Ack-Rcvd 2022-02-02T13:15:35 Informational ppp [wan_link0] MAGICNUM 0xe0085d10 2022-02-02T13:15:35 Informational ppp [wan_link0] MRU 1492 2022-02-02T13:15:35 Informational ppp [wan_link0] LCP: rec'd Configure Ack #2 (Req-Sent) 2022-02-02T13:15:35 Informational ppp [wan_link0] MAGICNUM 0xe0085d10 2022-02-02T13:15:35 Informational ppp [wan_link0] MRU 1492 2022-02-02T13:15:35 Informational ppp [wan_link0] LCP: SendConfigReq #2 2022-02-02T13:15:35 Informational ppp [wan_link0] PROTOCOMP 2022-02-02T13:15:35 Informational ppp [wan_link0] LCP: rec'd Configure Reject #1 (Req-Sent) 2022-02-02T13:15:35 Informational ppp [wan_link0] MAGICNUM 0xe0085d10 2022-02-02T13:15:35 Informational ppp [wan_link0] MRU 1492 2022-02-02T13:15:35 Informational ppp [wan_link0] PROTOCOMP 2022-02-02T13:15:35 Informational ppp [wan_link0] LCP: SendConfigReq #1 2022-02-02T13:15:35 Informational ppp [wan_link0] LCP: state change Starting --> Req-Sent 2022-02-02T13:15:35 Informational ppp [wan_link0] LCP: Up event 2022-02-02T13:15:35 Informational ppp [wan_link0] Link: UP event 2022-02-02T13:15:35 Informational ppp [wan_link0] PPPoE: connection successful 2022-02-02T13:15:34 Informational ppp PPPoE: rec'd ACNAME "************" 2022-02-02T13:15:34 Informational ppp [wan_link0] PPPoE: Connecting to '1und1' 2022-02-02T13:15:34 Informational ppp [wan_link0] LCP: LayerStart 2022-02-02T13:15:34 Informational ppp [wan_link0] LCP: state change Initial --> Starting 2022-02-02T13:15:34 Informational ppp [wan_link0] LCP: Open event 2022-02-02T13:15:34 Informational ppp [wan_link0] Link: OPEN event 2022-02-02T13:15:34 Informational ppp [wan] Bundle: Interface ng0 created 2022-02-02T13:15:34 Informational ppp web: web is not running 2022-02-02T13:15:34 Informational ppp process 14684 started, version 5.9 2022-02-02T13:15:34 Informational ppp 2022-02-02T13:15:34 Informational ppp Multi-link PPP daemon for FreeBSD 2022-02-02T13:15:34 Informational ppp process 53531 terminated 2022-02-02T13:15:34 Informational ppp [wan_link0] Link: Shutdown 2022-02-02T13:15:34 Informational ppp [wan] Bundle: Shutdown 2022-02-02T13:15:32 Informational ppp [wan_link0] LCP: Close event 2022-02-02T13:15:32 Informational ppp [wan_link0] Link: CLOSE event 2022-02-02T13:15:32 Informational ppp [wan_link0] LCP: state change Closing --> Initial 2022-02-02T13:15:32 Informational ppp [wan_link0] LCP: LayerFinish 2022-02-02T13:15:32 Informational ppp [wan_link0] LCP: Down event 2022-02-02T13:15:32 Informational ppp [wan_link0] LCP: state change Stopping --> Closing 2022-02-02T13:15:32 Informational ppp [wan_link0] LCP: Close event 2022-02-02T13:15:32 Informational ppp [wan_link0] Link: giving up after 0 reconnection attempts 2022-02-02T13:15:32 Informational ppp [wan_link0] Link: DOWN event 2022-02-02T13:15:32 Informational ppp [wan_link0] PPPoE: connection closed 2022-02-02T13:15:32 Informational ppp [wan_link0] LCP: LayerDown 2022-02-02T13:15:32 Informational ppp [wan_link0] LCP: SendTerminateAck #4 2022-02-02T13:15:32 Informational ppp [wan] IPV6CP: state change Closed --> Initial 2022-02-02T13:15:32 Informational ppp [wan] IPV6CP: Down event 2022-02-02T13:15:32 Informational ppp [wan] IPCP: state change Closed --> Initial 2022-02-02T13:15:32 Informational ppp [wan] IPCP: Down event 2022-02-02T13:15:32 Informational ppp [wan] IPV6CP: Close event 2022-02-02T13:15:32 Informational ppp [wan] IPCP: Close event 2022-02-02T13:15:32 Informational ppp [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps 2022-02-02T13:15:32 Informational ppp [wan_link0] Link: Leave bundle "wan" 2022-02-02T13:15:32 Informational ppp [wan_link0] LCP: state change Opened --> Stopping 2022-02-02T13:15:32 Informational ppp [wan_link0] LCP: rec'd Terminate Request #3 (Opened) 2022-02-02T13:15:32 Informational ppp [wan] Bundle: closing link "wan_link0"... 2022-02-02T13:15:32 Informational ppp [wan] Bundle: No NCPs left. Closing links... 2022-02-02T13:15:32 Informational ppp [wan] IPV6CP: LayerFinish 2022-02-02T13:15:32 Informational ppp [wan] IPV6CP: state change Closing --> Closed 2022-02-02T13:15:32 Informational ppp [wan] IPV6CP: rec'd Terminate Ack #2 (Closing) 2022-02-02T13:15:32 Informational ppp [wan] IPCP: LayerFinish 2022-02-02T13:15:32 Informational ppp [wan] IPCP: state change Closing --> Closed 2022-02-02T13:15:32 Informational ppp [wan] IPCP: rec'd Terminate Ack #4 (Closing) 2022-02-02T13:15:32 Informational ppp [wan] IPCP: SendTerminateReq #5 2022-02-02T13:15:32 Informational ppp [wan] IPV6CP: SendTerminateReq #3 2022-02-02T13:15:32 Informational ppp [wan] IFACE: Rename interface pppoe1 to pppoe1 2022-02-02T13:15:32 Informational ppp [wan] IFACE: Down event 2022-02-02T13:15:01 Informational ppp [wan] IPV6CP: LayerDown 2022-02-02T13:15:01 Informational ppp [wan] IPV6CP: SendTerminateReq #2 2022-02-02T13:15:01 Informational ppp [wan] IPV6CP: state change Opened --> Closing 2022-02-02T13:15:01 Informational ppp [wan] IPV6CP: Close event 2022-02-02T13:15:01 Informational ppp [wan] IFACE: Removing IPv4 address from pppoe1 failed: Can't assign requested address 2022-02-02T13:15:01 Informational ppp [wan] IFACE: Delete route 0.0.0.0/0 <IP> failed: No such process 2022-02-02T13:15:00 Informational ppp [wan] IPCP: LayerDown 2022-02-02T13:15:00 Informational ppp [wan] IPCP: SendTerminateReq #4 2022-02-02T13:15:00 Informational ppp [wan] IPCP: state change Opened --> Closing 2022-02-02T13:15:00 Informational ppp [wan] IPCP: Close event 2022-02-02T13:15:00 Informational ppp [wan] IFACE: Close event 2022-02-02T13:15:00 Informational ppp caught fatal signal TERM
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: franco on February 02, 2022, 01:31:55 pm: "DEVD" events from system log would be most helpful.

I mean we could get rid of -k option now and leave it at that. This sure is interesting and might explain some of the issues we've had the past with reconnect loops.

Cheers,
Franco
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: birdy on February 02, 2022, 02:21:28 pm: Patched my system too. Will report back tomorrow. Thanks so far.
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: chris42 on February 02, 2022, 09:06:31 pm: Quote from: franco on February 02, 2022, 01:31:55 pm
"DEVD" events from system log would be most helpful.

Hmm... a grep for "DEVD" on my latest log in /var/log/system does not find anything. Do I need to up some logging levels somewhere?
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: franco on February 02, 2022, 09:10:47 pm: Should look something like this

2022-01-06T08:05:58 Error opnsense-devel /usr/local/etc/rc.linkup: DEVD: Ethernet attached event for dynamic lan(igb0)

Cheers,
Franco
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: chris42 on February 03, 2022, 08:59:34 am: Nothing in my logs, however I have the patch installed. I assume this would only occur without the patch?
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: franco on February 03, 2022, 09:09:40 am: No this would always be, but maybe I'm overthinking it and it doesn't happen on the PPPoE interface.

So now with the patch this works better?

Cheers,
Franco
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: birdy on February 03, 2022, 09:17:41 am: So this morning everything is working fine. So I would say: problem solved.

BTW
No DEVD in the logging over here.
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: franco on February 03, 2022, 09:19:57 am: And that's with only one nightly cron job in there? Apply might have been forgotten (happens to me too). Just double-checking.

Cheers,
Franco
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: chris42 on February 03, 2022, 09:35:09 am: Yes, patch was working tonight in one single cron job, so far no issues. Definitely applied the cron table, as I changed it multiple times yesterday for testing.
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: franco on February 03, 2022, 09:37:34 am: Super, thanks. I think we'll add this to 22.1.1 then. I don't have a technical objection at this point.

Cheers,
Franco
Title: Re: WAN Interface lost connection after "reset interface" (pppoe)
Post by: birdy on February 03, 2022, 10:03:15 am: Quote from: franco on February 03, 2022, 09:19:57 am
And that's with only one nightly cron job in there? Apply might have been forgotten (happens to me too). Just double-checking.

Yes this is with running the cron at 3:07 only :)