Nefunkční automatická záloha do cloudu

Ahoj,
od 2.9. mi nefunguje automatická záloha do cloudu.
při zadání root@turris:~# updater-resume.sh dostávám:

Traceback (most recent call last):
File “/usr/bin/foris-client”, line 11, in
load_entry_point(‘foris-client==1.0.2’, ‘console_scripts’, ‘foris-client’)()
File “/usr/lib/python3.6/site-packages/foris_client/client/main.py”, line 177, in main
response = sender.send(options.module, options.action, data, **kwargs)
File “/usr/lib/python3.6/site-packages/foris_client/buses/ubus.py”, line 127, in send
self._raise_exception_on_error(response)
File “/usr/lib/python3.6/site-packages/foris_client/buses/base.py”, line 69, in _raise_exception_on_error
raise generate_controller_error(msg[“module”], msg[“action”])(msg[“errors”])
foris_client.buses.base.ControllerError__ssbackups__create_and_upload: Controller error(s) has occured:
Traceback (most recent call last):
File “/usr/lib/python3.6/site-packages/foris_controller/message_router.py”, line 117, in process_message
data = module_instance.perform_action(message[“action”], message.get(“data”, {}))
File “/usr/lib/python3.6/site-packages/foris_controller/module_base.py”, line 61, in perform_action
res = action_function(data)
File “/usr/lib/python3.6/site-packages/foris_controller_modules/ssbackups/init.py”, line 36, in action_create_and_upload
new_id, result = self.handler.create_and_upload()
File “/usr/lib/python3.6/site-packages/foris_controller/utils.py”, line 112, in inner
res = func(*args, **kwargs)
File “/usr/lib/python3.6/site-packages/foris_controller_modules/ssbackups/handlers/openwrt.py”, line 52, in create_and_upload
backup = self.maintain_cmds.generate_backup() # configuration backup (encoded in base64)
File “/usr/lib/python3.6/site-packages/foris_controller_backends/maintain/init.py”, line 48, in generate_backup
raise BackendCommandFailed(retval, [cmd])
foris_controller.exceptions.BackendCommandFailed: Retval=1 for [’/usr/bin/maintain-config-backup’]

Internal error Retval=1 for [’/usr/bin/maintain-config-backup’](’<class ‘foris_controller.exceptions.BackendCommandFailed’>’)

Dále jsem zjistil, že nefunguje ucollect (stále je ofline), což s tím asi souvisí.
System logu jsou tyto hlášky
2019-09-08 09:01:00 err ucollect[8991]: Error from socat: 2019/09/08 09:01:00 socat[9227] E SSL_connect(): error:14090086:lib(20):func(144):reason(134)
2019-09-08 09:01:00 warning ucollect[8991]: Remote closed the uplink api.turris.cz:5679, reconnecting
2019-09-08 09:01:00 warning ucollect[8991]: epoll_wait on 4 interrupted, retry
2019-09-08 09:01:00 info ucollect[8991]: Reconnecting to api.turris.cz:5679 now
2019-09-08 09:01:00 warning ucollect[8991]: Reconnecting too often, waiting a little while
2019-09-08 09:01:00 info ucollect[8991]: Going to reconnect to api.turris.cz:5679 after 64 seconds
2019-09-08 09:01:01 err server_uplink[]: Failed to get registration code

Vypadá to jako problém v registračním kódu, ale nic jsem na portálu neměnil. Můžete mi pomoc, jak to opravit? Díky.

Trochu podobné, ale u mne bude jiný důvod

https://forum.turris.cz/t/vytvoreni-partition-fdiskem/10906/28?u=jardab

Výběr chyb z logu

2019-09-08 12:13:22 err ucollect[30006]: Error from socat: 2019/09/08 12:13:22 socat[31962] E SSL_connect(): error:14090086:lib(20):func(144):reason(134)
2019-09-08 12:13:22 warning ucollect[30006]: Remote closed the uplink api.turris.cz:5679, reconnecting
2019-09-08 12:13:22 warning ucollect[30006]: epoll_wait on 4 interrupted, retry
2019-09-08 12:13:22 info ucollect[30006]: Reconnecting to api.turris.cz:5679 now
2019-09-08 12:13:22 warning ucollect[30006]: Reconnecting too often, waiting a little while
2019-09-08 12:13:22 info ucollect[30006]: Going to reconnect to api.turris.cz:5679 after 300 seconds
2019-09-08 12:13:52 warning odhcpd[3347]: DHCPV6 SOLICIT IA_NA from 000300010011320d2cfc on br-lan: ok fdfa:9aeb:3b6d::a8c/128 
2019-09-08 12:14:01 info /usr/sbin/cron[32025]: (root) CMD (/usr/bin/rainbow_button_sync.sh)
2019-09-08 12:14:01 info /usr/sbin/cron[32026]: (root) CMD (nethist_stats.lua)
2019-09-08 12:14:15 info updater-supervisor[]: Running pkgupdate
2019-09-08 12:14:25 warning updater[32050]: planner.lua:344 (pkg_plan): Requested package foris-pakon-plugin-l10n-de that is missing, ignoring as requested.
2019-09-08 12:14:25 warning updater[32050]: planner.lua:344 (pkg_plan): Requested package foris-storage-plugin-l10n-de that is missing, ignoring as requested.
2019-09-08 12:14:25 warning updater[32050]: planner.lua:344 (pkg_plan): Requested package luci-i18n-ddns-en that is missing, ignoring as requested.
2019-09-08 12:14:25 warning updater[32050]: planner.lua:465 (Globals): Request not satisfied to install package: nikola
2019-09-08 12:14:25 info updater-supervisor[]: pkgupdate reported no errors

x

2019-09-08 12:19:22 info ucollect[32676]: Initializing emergency signal handlers
2019-09-08 12:19:22 info ucollect[32676]: Creating a main loop
2019-09-08 12:19:22 info ucollect[32676]: Creating uplink
2019-09-08 12:19:22 info ucollect[32676]: Initializing PCAP (in) on eth1
2019-09-08 12:19:22 info ucollect[32676]: Initializing PCAP (out) on eth1
2019-09-08 12:19:22 info ucollect[32676]: Initializing PCAP (in) on lo
2019-09-08 12:19:22 info ucollect[32676]: Initializing PCAP (out) on lo
2019-09-08 12:19:22 info ucollect[32676]: Loading plugin library libplugin_ucollect_badconf_25.so
2019-09-08 12:19:22 info ucollect[32676]: Installing plugin Badconf with api version 0
2019-09-08 12:19:22 info ucollect[32676]: Loading plugin library libplugin_ucollect_bandwidth_22.so
2019-09-08 12:19:22 info ucollect[32676]: Installing plugin Bandwidth with api version 0
2019-09-08 12:19:22 info ucollect[32676]: Loading plugin library libplugin_ucollect_count_28.so
2019-09-08 12:19:22 info ucollect[32676]: Installing plugin Count with api version 0
2019-09-08 12:19:22 info ucollect[32676]: Loading plugin library libplugin_ucollect_fake_23.so
2019-09-08 12:19:22 info ucollect[32676]: Installing plugin Fake with api version 0
2019-09-08 12:19:22 info ucollect[32676]: Loading plugin library libplugin_ucollect_flow_33.so
2019-09-08 12:19:22 info ucollect[32676]: Installing plugin Flow with api version 2
2019-09-08 12:19:22 info ucollect[32676]: Loading plugin library libpluglib_ucollect_diffstore_1.2.so
2019-09-08 12:19:22 info ucollect[32676]: Loading plugin library libplugin_ucollect_fwup_12.so
2019-09-08 12:19:22 info ucollect[32676]: Installing plugin Fwup with api version 2
2019-09-08 12:19:22 info ucollect[32676]: Loading plugin library libpluglib_ucollect_diffstore_1.2.so
2019-09-08 12:19:22 info ucollect[32676]: Loading plugin library libplugin_ucollect_refused_13.so
2019-09-08 12:19:22 info ucollect[32676]: Installing plugin Refused with api version 0
2019-09-08 12:19:22 info ucollect[32676]: Loading plugin library libplugin_ucollect_sniff_19.so
2019-09-08 12:19:22 info ucollect[32676]: Installing plugin Sniff with api version 0
2019-09-08 12:19:22 info ucollect[32676]: Loading plugin library libplugin_ucollect_spoof_8.so
2019-09-08 12:19:22 info ucollect[32676]: Installing plugin Spoof with api version 0
2019-09-08 12:19:22 info ucollect[32676]: Changing remote uplink address to api.turris.cz:5679
2019-09-08 12:19:22 info ucollect[32676]: Sending login credentials enabled
2019-09-08 12:19:22 info ucollect[31832]: Last message 'Sending login creden' repeated 5 times, suppressed by syslog-ng on turris
2019-09-08 12:19:22 info ucollect[32676]: Unloading plugin library
2019-09-08 12:19:22 info ucollect[32676]: Running the main loop
2019-09-08 12:19:22 info ucollect[32676]: Reconnecting to api.turris.cz:5679 now
2019-09-08 12:19:22 info ucollect[32676]: Socat started
2019-09-08 12:19:22 err ucollect[32676]: Error from socat: 2019/09/08 12:19:22 socat[32684] E connect(5, AF=10 [2001:1488:ac15:ff80:0000:0000:0000:0101]:5679, 28): Permission denied
2019-09-08 12:19:22 warning ucollect[32676]: Remote closed the uplink api.turris.cz:5679, reconnecting
2019-09-08 12:19:22 warning ucollect[32676]: epoll_wait on 4 interrupted, retry
2019-09-08 12:19:22 info ucollect[32676]: Reconnecting to api.turris.cz:5679 now
2019-09-08 12:19:22 warning ucollect[32676]: Reconnecting too often, waiting a little while
2019-09-08 12:19:22 info ucollect[32676]: Going to reconnect to api.turris.cz:5679 after 2 seconds
2019-09-08 12:19:24 info ucollect[32676]: Reconnecting to api.turris.cz:5679 now
2019-09-08 12:19:24 info ucollect[32676]: Socat started
2019-09-08 12:19:24 err ucollect[32676]: Error from socat: 2019/09/08 12:19:24 socat[32687] E SSL_connect(): error:14090086:lib(20):func(144):reason(134)
2019-09-08 12:19:24 warning ucollect[32676]: Remote closed the uplink api.turris.cz:5679, reconnecting
2019-09-08 12:19:24 warning ucollect[32676]: epoll_wait on 4 interrupted, retry
2019-09-08 12:19:24 info ucollect[32676]: Reconnecting to api.turris.cz:5679 now
2019-09-08 12:19:24 warning ucollect[32676]: Reconnecting too often, waiting a little while
2019-09-08 12:19:24 info ucollect[32676]: Going to reconnect to api.turris.cz:5679 after 4 seconds
2019-09-08 12:19:28 info ucollect[32676]: Reconnecting to api.turris.cz:5679 now
2019-09-08 12:19:28 info ucollect[32676]: Socat started
2019-09-08 12:19:29 err ucollect[32676]: Error from socat: 2019/09/08 12:19:29 socat[32692] E connect(5, AF=10 [2001:1488:ac15:ff80:0000:0000:0000:0101]:5679, 28): Permission denied
2019-09-08 12:19:29 warning ucollect[32676]: Remote closed the uplink api.turris.cz:5679, reconnecting
2019-09-08 12:19:29 warning ucollect[32676]: epoll_wait on 4 interrupted, retry
2019-09-08 12:19:29 info ucollect[32676]: Reconnecting to api.turris.cz:5679 now
2019-09-08 12:19:29 warning ucollect[32676]: Reconnecting too often, waiting a little while
2019-09-08 12:19:29 info ucollect[32676]: Going to reconnect to api.turris.cz:5679 after 8 seconds
2019-09-08 12:19:37 info ucollect[32676]: Reconnecting to api.turris.cz:5679 now
2019-09-08 12:19:37 info ucollect[32676]: Socat started
2019-09-08 12:19:37 err ucollect[32676]: Error from socat: 2019/09/08 12:19:37 socat[32701] E SSL_connect(): error:14090086:lib(20):func(144):reason(134)
2019-09-08 12:19:37 warning ucollect[32676]: Remote closed the uplink api.turris.cz:5679, reconnecting
2019-09-08 12:19:37 warning ucollect[32676]: epoll_wait on 4 interrupted, retry
2019-09-08 12:19:37 info ucollect[32676]: Reconnecting to api.turris.cz:5679 now
2019-09-08 12:19:37 warning ucollect[32676]: Reconnecting too often, waiting a little while
2019-09-08 12:19:37 info ucollect[32676]: Going to reconnect to api.turris.cz:5679 after 16 seconds
2019-09-08 12:19:53 info ucollect[32676]: Reconnecting to api.turris.cz:5679 now
2019-09-08 12:19:53 info ucollect[32676]: Socat started

To pravděpodobně úzce souvisí s tímto odkazem: Ucollect failing talking to api.turris.cz port 5679 , takže až se to vyřeší, měl by zase zafungovat uCollect.

EDIT: Oprava - myslel jsem uCollect, u zálohování nevím, omlouvám se za překlep.

Dobry den, uCollect server je aktualne nedostupny, nicmene vzdalene zalohy (cloud backups) nejsou ovlivneny. Napr. na mem routeru jsem pred chvilkou zalohu bez problemu vytvoril.

uCollect server je zase dostupný, ale zálohy mi stále nefungují. Je někde možné najít příčinu?

Ucollect nebo zálohy konfigurace ?Dotaz není jasný

Mně cloudové zálohy fungují, Turris 1.0, RC verze 3.11.7 z Forisu…

Stále řeším zálohu konfigurace.
Díval jsem se do system logu a mám tam
2019-10-05 01:57:58 err foris-controller[17188]: ERROR:foris_controller_backends.maintain:Cmd which generates the backup ‘/usr/bin/maintain-config-backup’ failed.
2019-10-05 01:57:58 err foris-controller[17188]: ERROR:foris_controller.message_router:Internal error occured <class ‘foris_controller.exceptions.BackendCommadFailed’>(‘Retval=1 for [’/usr/bin/maintain-config-backup’]’):

a potom ještě toto (ale nevím jestli to s tím souvisí)
2019-10-05 02:00:01 err server_uplink[]: Failed to download contract status

Poslední chyba se vyskytovala i v minulosti … viz forum. Já ji odstranil vždy přesunutím této akce na jiné časy. Nevím proč to už není opraveno i defaultním nastavení ?

1 Like

Díky za tip, chyby zmizeli :-), kromě zálohy do cloudu :frowning:
Zkusil jsem balíčky odebrat a zase přidat, ale záloha stejně nefunguje. Reset do továrního nastavení se mi nechce dělat.

Jen pro jistotu - kterou verzi systému máš, poslední ? (chyby s uplinkem a api byly ve starší verzi … nyní odstraněné )

Ve Foris má aktivovaný sběr dat ?

Verze je 3.11.7
Sběr dat je aktivovaný. Jen při deaktivaci a následné aktivaci dostávám toto

Remote Exception: Internal error Calling ‘enable’ for service ‘ucollect’ failed.(’<class ‘foris_controller.exceptions.ServiceCmdFailed’>’)

Traceback (most recent call last):
File “/usr/lib/python3.6/site-packages/foris_controller/message_router.py”, line 117, in process_message
data = module_instance.perform_action(message[“action”], message.get(“data”, {}))
File “/usr/lib/python3.6/site-packages/foris_controller/module_base.py”, line 61, in perform_action
res = action_function(data)
File “/usr/lib/python3.6/site-packages/foris_controller_modules/data_collect/init.py”, line 56, in action_set
res = self.handler.set_agreed(data[“agreed”])
File “/usr/lib/python3.6/site-packages/foris_controller/utils.py”, line 113, in inner
res = func(*args, **kwargs)
File “/usr/lib/python3.6/site-packages/foris_controller_modules/data_collect/handlers/openwrt.py”, line 69, in set_agreed
return self.uci.set_agreed(agreed)
File “/usr/lib/python3.6/site-packages/foris_controller_backends/data_collect/init.py”, line 121, in set_agreed
services.enable(“ucollect”)
File “/usr/lib/python3.6/site-packages/foris_controller_backends/services/init.py”, line 137, in enable
self._run_service_command(service_name, “enable”, fail_on_error)
File “/usr/lib/python3.6/site-packages/foris_controller_backends/services/init.py”, line 79, in _run_service_command
raise ServiceCmdFailed(service_name, cmd)
foris_controller.exceptions.ServiceCmdFailed: Calling ‘enable’ for service ‘ucollect’ failed.

ale sběr dat je zapnutý…

po pár minutách vidím…
|Data uCollect: |Online stav aktualizován před 54 sekundami|
|Záznamy (log) z brány firewall: |Online stav aktualizován před 798 sekundami|

Tak už jsem našel, kde byla závada :slight_smile: Ještě jednou jsem to celý prošel a zjistil jsem, že v souboru etc/config/backup mám nastavenou zálohu souboru, který jsem si už smazal. Když jsem to opravil, tak záloha začala chodit.
Když to člověk nedělá každý den, tak si nevzpomene na ty souvislosti :frowning:

1 Like