WAN Interface lost connection after "reset interface" (pppoe)

Started by ducky87, January 31, 2022, 09:45:01 AM

Previous topic - Next topic
Print
Go Down Pages1 2
User actions
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.
January 31, 2022, 12:31:23 PM #1
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.
Assumption is the mother of all f... ups!
January 31, 2022, 02:01:03 PM #2
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
January 31, 2022, 04:43:01 PM #3 Last Edit: January 31, 2022, 04:47:00 PM by birdy
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.
Assumption is the mother of all f... ups!
January 31, 2022, 09:54:38 PM #4
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.
Assumption is the mother of all f... ups!
January 31, 2022, 10:39:06 PM #5
I have the same problem


Gesendet von iPad mit Tapatalk Pro
February 02, 2022, 08:04:26 AM #6
I noticed the same issue with PPPOE and periodic interface reset.
February 02, 2022, 09:11:33 AM #7 Last Edit: February 02, 2022, 10:22:07 AM by franco
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
February 02, 2022, 10:18:43 AM #8
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
February 02, 2022, 10:21:57 AM #9
Sorry typo, should have been:

# pgrep mpd5


Cheers,
Franco
February 02, 2022, 10:31:06 AM #10
mpd5 läuft auch.

Würde ein ppp log helfen, wenn ich den cron für die Trennung mal eben nach vorne ziehe?
February 02, 2022, 10:55:01 AM #11
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...
February 02, 2022, 11:20:32 AM #12
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
February 02, 2022, 11:46:29 AM #13
https://github.com/opnsense/core/commit/3ccd2f0bdf07

Can you try this one?

# opnsense-patch 3ccd2f0bdf07


Cheers,
Franco
February 02, 2022, 12:38:01 PM #14
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
Print
Go Up Pages1 2
User actions