WB4 самопроизвольно перезагружается при apt-get update

Добрый день!

Купил контроллер WB4 в начале ноября. Несколько дней назад подготовил разводку в доме и начал подключать контроллер, до этого он просто лежал в коробке. При попытке обновить список пакетов через apt-get update контроллер стабильно самопроизвольно перезагружается, судя по всему в тот момент когда начинается распаковка bzip2 архивов. Попробовал залить на SD-шку самый последний образ для WB4 (0.12-20151111) - результат тот же. Вот что я вижу на консоли через UART:
[1 Packages bzip2 16.2 MB]100% [1 Packages bzip2 16.2 MB]HTLCmxs_power_init(): mxs_power_init mxs_power_set_auto_restart(): mxs_power_set_auto_restart mxs_power_set_linreg(): mxs_power_set_linreg mxs_power_configure_power_source(): mxs_power_configure_power_source mxs_get_batt_volt(): mxs_get_batt_volt volt=728 mV mxs_power_configure_power_source(): not batt_ready mxs_is_batt_good(): mxs_is_batt_good mxs_get_batt_volt(): mxs_get_batt_volt volt=728 mV mxs_get_batt_volt(): mxs_get_batt_volt volt=4192 mV
и дальше идет весь лог загрузки. Вероятно контроллер перезагружается и ещё в каких-то ситуациях. Такое впечатление что перезагрузка происходит когда процессор сильно загружен. Блок питания 12В 3А, пробовал два разных.

Что делать? Куда смотреть?

С уважением,
Андрей

Скорее всего не хватает памяти.
Попробуйте остановить все сервисы wb-*

Остановил все сервисы wb-* и nginx. Тот же эффект:
Ign http://ftp.us.debian.org wheezy/main Translation-en 61% [1 Packages gzip 5399 kB]HTLCmxs_power_init(): mxs_power_init mxs_power_set_auto_restart(): mxs_power_set_auto_restart mxs_power_set_linreg(): mxs_power_set_linreg mxs_power_configure_power_source(): mxs_power_configure_power_source mxs_get_batt_volt(): mxs_get_batt_volt volt=696 mV mxs_power_configure_power_source(): not batt_ready mxs_is_batt_good(): mxs_is_batt_good
Состояние памяти перед apt-get update:
root@wirenboard:~# free total used free shared buffers cached Mem: 58792 46664 12128 0 3540 31344 -/+ buffers/cache: 11780 47012 Swap: 262140 712 261428

Надеюсь, что разработчики смогут более квалифицированный ответ, но:

  1. У меня на WB4 была крайне похожая проблема, которая лечилась выгрузкой всего лишнего из памяти
  2. mxs_get_batt_volt volt=728 mV а через некоторое время mxs_get_batt_volt volt=4192 mV уж очень похоже на реальные проблемы с питанием…
  • Попробовать мультиметром смотреть питание? Хотя по идее нужно смотреть его не на входе, а на самом модуле или где-то рядом
  • Отключить GSM модуль (он может потреблять реально очень много)?
  • Батарейка есть или нет? Если есть - попробовать отключить?
  • Попробовать чем-то нагрузить процессор. Повторится проблема или нет…

Меня тоже настораживают сообщения про батарейку. Но блок питания я менял, сейчас он вообще от ноутбука, выдаёт 12В, мощность 4.5А - должен быть стабильней некуда. Одновременно сбоить батарейка и 2 блока питания - как-то мне это странно.
Попробовал нагрузить процессор - вот так:
tar cvzf - /usr > /dev/null
результат - минуту или две работало нормально, потом вот так:
/usr/lib/perl/5.14.2/auto/Encode/Symbol/Symbol.so /usr/lib/perl/5.14.2/auto/Encode/JP/ /usr/lib/perl/5.14.2/auto/Encode/JP/JP.so [ 2760.300000] INFO: task wb-mqtt-db:2563 blocked for more than 120 seconds. [ 2760.300000] Tainted: G C 3.19.0-imxv5-x0.1 #455 [ 2760.310000] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 2760.320000] wb-mqtt-db D c03e7c34 0 2563 1 0x00000000 [ 2760.320000] [<c03e7c34>] (__schedule) from [<c03e8148>] (io_schedule+0xb0/0x128) [ 2760.330000] [<c03e8148>] (io_schedule) from [<c03e8828>] (bit_wait_io+0x34/0x58) [ 2760.340000] [<c03e8828>] (bit_wait_io) from [<c03e8500>] (__wait_on_bit+0x84/0xbc) [ 2760.350000] [<c03e8500>] (__wait_on_bit) from [<c006ee30>] (wait_on_page_bit+0xc0/0xd4) [ 2760.350000] [<c006ee30>] (wait_on_page_bit) from [<c006ef6c>] (filemap_fdatawait_range+0xd8/0x12c) [ 2760.360000] [<c006ef6c>] (filemap_fdatawait_range) from [<c006fe44>] (filemap_write_and_wait_range+0x54/0x74) [ 2760.370000] [<c006fe44>] (filemap_write_and_wait_range) from [<c01031e8>] (ext4_sync_file+0x60/0x260) [ 2760.380000] [<c01031e8>] (ext4_sync_file) from [<c00cef40>] (do_fsync+0x50/0x78) [ 2760.390000] [<c00cef40>] (do_fsync) from [<c000ee60>] (ret_fast_syscall+0x0/0x30) [ 2760.400000] INFO: task kworker/u2:0:2784 blocked for more than 120 seconds. [ 2760.400000] Tainted: G C 3.19.0-imxv5-x0.1 #455 [ 2760.410000] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 2760.420000] kworker/u2:0 D c03e7c34 0 2784 2 0x00000000 [ 2760.430000] Workqueue: kmmcd mmc_rescan [ 2760.430000] [<c03e7c34>] (__schedule) from [<c02a8820>] (__mmc_claim_host+0x88/0x19c) [ 2760.440000] [<c02a8820>] (__mmc_claim_host) from [<c02af558>] (mmc_sd_detect+0x1c/0x70) [ 2760.450000] [<c02af558>] (mmc_sd_detect) from [<c02aabf8>] (mmc_rescan+0x170/0x2cc) [ 2760.450000] [<c02aabf8>] (mmc_rescan) from [<c002d1dc>] (process_one_work+0x110/0x324) [ 2760.460000] [<c002d1dc>] (process_one_work) from [<c002d468>] (worker_thread+0x44/0x470) [ 2760.470000] [<c002d468>] (worker_thread) from [<c00316c4>] (kthread+0xc0/0xdc) [ 2760.480000] [<c00316c4>] (kthread) from [<c000eef8>] (ret_from_fork+0x14/0x3c)
и т.д.
По Ctrl-C вышло обратно в промпт.
Остальные эксперименты попробую завтра, но может быть разработчики что-нибудь подскажут.

Сообщения про batt можно смело игнорировать, это загрузчик говорит про вход BATT процессора, который у нас на WB4 вообще никуда не подключен.

На WB4 может быть две с половиной проблемы с такими симптомами:

  1. Мы наблюдали в редких случаях перезагрузки при одновременном очень активном обмене данными с памятью и карточкой. Обычно это проявляется в случаях, когда контроллер ушёл в своп. apt-get и при загруженных наших сервисах такое может вызывать
  2. Теоретически, если нагрузка на процессор (по I/O в т.ч., см первый пункт) будет такая, что процессор пропустит в течение нескольких секунд опрос watchdog-а, то watchdog может перезапустить контроллер
  3. В конце концов это может быть банально брак памяти. Проверять так: убить вообще всё что можно, чтобы максимально освободить память, потом сделать команду memtester 40M и оставить на несколько часов

С tar и mmc - это не связанные вещи. Вы так нагрузили контроллер (по I/O в первую очередь), что у него wb-mqtt-db 2 минуты стояло в очереди к флешке, вот вас линукс и предупредил.

Напишите ещё пожалуйста s/n, можно в почту.

Весь день крутился memtester на 45M - уже больше 30 циклов без ошибок. Так что память в порядке вроде.

Странно это всё. По железу тоже всё хорошо, ревизия процессора и памяти беспроблемные.

Можете ещё попробовать своп отключить?

Спасибо за идею - с отключенным свопом apt-get update прошел нормально, apt-get upgrade вывалил несколько ошибок - но по крайней мере не было перезагрузок. Что с этим можно сделать? Проверить swap-раздел?

Кстати, может подскажете ещё что с ошибками apt-get upgrade делать:
perl: warning: Setting locale failed. perl: warning: Please check that your locale settings: LANGUAGE = (unset), LC_ALL = (unset), LANG = "en_NZ.UTF-8" are supported and installed on your system. perl: warning: Falling back to the standard locale ("C"). locale: Cannot set LC_CTYPE to default locale: No such file or directory locale: Cannot set LC_MESSAGES to default locale: No such file or directory locale: Cannot set LC_ALL to default locale: No such file or directory Extracting templates from packages: 100% Preconfiguring packages ... (Reading database ... 17504 files and directories currently installed.) Preparing to replace base-files 7.1wheezy9 (using .../base-files_7.1wheezy10_armel.deb) ... Unpacking replacement base-files ... Setting up base-files (7.1wheezy10) ... Installing new version of config file /etc/debian_version ... (Reading database ... 17504 files and directories currently installed.) Preparing to replace dpkg 1.16.16 (using .../dpkg_1.16.17_armel.deb) ... Unpacking replacement dpkg ... Setting up dpkg (1.16.17) ... (Reading database ... 17504 files and directories currently installed.) Preparing to replace perl 5.14.2-21+deb7u2 (using .../perl_5.14.2-21+deb7u3_armel.deb) ... Unpacking replacement perl ... Preparing to replace libperl5.14 5.14.2-21+deb7u2 (using .../libperl5.14_5.14.2-21+deb7u3_armel.deb) ... Unpacking replacement libperl5.14 ... Preparing to replace perl-base 5.14.2-21+deb7u2 (using .../perl-base_5.14.2-21+deb7u3_armel.deb) ... Unpacking replacement perl-base ... Setting up perl-base (5.14.2-21+deb7u3) ... (Reading database ... 17494 files and directories currently installed.) Preparing to replace perl-modules 5.14.2-21+deb7u2 (using .../perl-modules_5.14.2-21+deb7u3_all.deb) ... Unpacking replacement perl-modules ... dpkg-deb (subprocess): decompressing archive member: internal gzip read error: '<fd:4>: incorrect data check' dpkg-deb: error: subprocess <decompress> returned error exit status 2 dpkg: error processing /var/cache/apt/archives/perl-modules_5.14.2-21+deb7u3_all.deb (--unpack): subprocess dpkg-deb --fsys-tarfile returned error exit status 2 Preparing to replace libc-bin 2.13-38+deb7u8 (using .../libc-bin_2.13-38+deb7u9_armel.deb) ... Unpacking replacement libc-bin ... Errors were encountered while processing:E: Sub-process /usr/bin/dpkg returned an error code (1)

Вообще такое впечатление что gzip при обновлении отругивается на файлы - может это значить что какие-то ошибки флеш-памяти? Типа читается не то что пишется?

И таки при попытке выполнить
apt-get -f install
контроллер самопроизвольно перезагрузился - вот на этом месте
Setting up libc-bin (2.13-38+deb7u9) ... (Reading database ... 17494 files and directories currently installed.) Preparing to replace libc6:armel 2.13-38+deb7u8 (using .../libc6_2.13-38+deb7u9_armel.deb) ... Unpacking replacement libc6:armel ... packet_write_wait: Connection to 10.218.125.193: Broken pipe

Выглядит именно так, либо порча данных на флеш-карте, либо в оперативной памяти.
Давайте мы вам поменяем контроллер просто, а что такое с этим случилось уже будем сами разбираться.

Коллеги с вами свяжутся по поводу обмена.

Да, хорошо! Озадачиваюсь передачей контроллера в Москву.

WB4 стал перезагружаться, в логах до перезагрузки чисто. Залит 201511111910 образ apt-get update. apt-get upgrade с перезагрузками и dpkg --reconfigure.

wb: ~# free
total used free shared buffers cached
Mem: 58596 54192 4404 0 4304 22680
-/+ buffers/cache: 27208 31388
Swap: 262140 0 262140

wb:~# ps -e -o pid,vsz,comm= | sort -n -k 2
PID VSZ
1242 0 jbd2/mmcblk0p6-
1243 0 ext4-rsv-conver
1351 0 kworker/0:1H
1604 0 RTW_CMD_THREAD
2427 1688 netplugd
2159 1704 startpar
2717 1704 startpar
2790 1740 watchdog
2142 1840 inotifywait
2694 1840 inotifywait
2808 2076 getty
1 2160 init
2201 2328 syslogd
2204 2328 klogd
2961 2624 ps
2130 2764 wb-watch-config
2143 2764 wb-watch-config
2691 2776 wb-watch-update
2695 2776 wb-watch-update
234 2784 udevd
235 2784 udevd
153 2868 udevd
2244 3304 dnsmasq
2833 3308 bash
2962 5268 sort
2278 5708 mosquitto
2441 5904 ntpd
2476 6260 sshd
2809 9444 sshd
2459 46580 nginx
2460 46780 nginx
2461 46780 nginx
2462 46780 nginx
2463 46780 nginx

Завтра заменю SD,
прибил все wb-*, memtester запустил - перезагрузка

Похоже на брак, свяжемся по вопросу замены.

Подниму тему. У меня wb4 перезагружается в 4 случаях из 5 при выполнении apt-get update. В логах все чисто:

Jan 11 08:14:40 wirenboard-ABOON5CN auth.info sshd[32227]: lastlog_openseek: Couldn't stat /var/log/lastlog: No such file or directory
Jan 11 08:14:40 wirenboard-ABOON5CN auth.info sshd[32227]: lastlog_openseek: Couldn't stat /var/log/lastlog: No such file or directory
Jan 11 08:19:56 wirenboard-ABOON5CN daemon.info wb-mqtt-confed[32379]: INFO: MQTT connection established
Jan 11 08:25:37 wirenboard-ABOON5CN daemon.info wb-mqtt-confed[32379]: ERROR: Invalid config file /etc/network/interfaces
Jan 11 08:25:37 wirenboard-ABOON5CN daemon.info wb-mqtt-confed[32379]: ERROR: - interfaces.1: Must validate one and only one schema (oneOf)
Jan 11 08:25:37 wirenboard-ABOON5CN daemon.info wb-mqtt-confed[32379]: ERROR: - method: method is required
Jan 11 08:25:37 wirenboard-ABOON5CN daemon.info wb-mqtt-confed[32379]: ERROR: - interfaces.1: Must validate all the schemas (allOf)
Jan 11 08:27:51 wirenboard-ABOON5CN daemon.info wb-rules[2601]: INFO: reloading file: /etc/wb-rules/heater.js
Jan 11 08:33:13 wirenboard-ABOON5CN auth.info sshd[32695]: reverse mapping checking getaddrinfo for cam-street.21.34.168.192.in-addr.arpa [192.168.34.21] failed - POSSIBLE BREAK-IN
ATTEMPT!
Jan 11 08:33:17 wirenboard-ABOON5CN auth.info sshd[32695]: Accepted password for root from 192.168.34.21 port 58966 ssh2
Jan 11 08:33:17 wirenboard-ABOON5CN authpriv.info sshd[32695]: pam_unix(sshd:session): session opened for user root by (uid=0)
Jan 11 08:35:38 wirenboard-ABOON5CN daemon.info wb-mqtt-confed[32379]: WARNING: MQTT connection lost
Jan 11 08:35:39 wirenboard-ABOON5CN daemon.info wb-mqtt-confed[32379]: INFO: MQTT connection established
Jan 11 08:46:49 wirenboard-ABOON5CN syslog.info syslogd started: BusyBox v1.20.2
Jan 11 08:46:49 wirenboard-ABOON5CN user.debug kernel: [    0.000000]   Normal zone: 128 pages used for memmap
Jan 11 08:46:49 wirenboard-ABOON5CN user.debug kernel: [    0.000000]   Normal zone: 0 pages reserved
Jan 11 08:46:49 wirenboard-ABOON5CN user.debug kernel: [    0.000000]   Normal zone: 16384 pages, LIFO batch:3
Jan 11 08:46:49 wirenboard-ABOON5CN user.debug kernel: [    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
Jan 11 08:46:49 wirenboard-ABOON5CN user.debug kernel: [    0.000000] pcpu-alloc: [0] 0

Скорее всего брак, если ещё на гарантии - поменяем без разговоров. Если не на гарантии - напишите пожалуйста на support@, посмотрим, что получится сделать.

Ок, напишу на support@. А сколько у вас лет гарантии? Я покупал в августе 2015.

Кстати, “активно” перезагружаться начала после обновления прошивки до последней (https://github.com/contactless/wirenboard/releases/download/0.27-20161019/201610251522_sdcard_4_alliance.img.zip). На старой прошивке бывало, но редко.

Спасибо, письмо получили.

Про прошивку это интересно, можете сказать серйиный номер устройства? Он написан на наклейке на корпусе обычно.

отправил всю инфу на емейл