j-Serie DS210j erkennt urplötzlich keine USB-Geräte mehr!

[nosi]

Hallo zusammen,

die Diskstation(DS210j, DSM 4.1-2661) erkennt keine USB Geräte mehr, vorher wurden die Geräte definitiv erkannt. Hier der chronologische Ablauf:

• Die Diskstation hat letzten Freitag (8.2.) wie immer freitags die Datensicherung auf die externe USB-Platte gestartet (verschlüsseltes Backup über Merthos Autorun-Paket, besten Dank an Merthos an dieser Stelle für das tolle Paket! Das Paket startet das Backup und wirft anschließend die Platte aus)
• Am Samstag (9.2.) bekam ich die Mail, dass die Datensicherung fehlgeschlagen sei fehlgeschlagen
• Am Montag (11.2.) habe ich mich dem Problem angenommen und wollte die Datensicherung erneut starten. Ich war etwas verwundert, dass das Autorun-Script nicht gestartet wurde beim einschalten der externen Platte, also habe ich mir das mal genauer angesehen und festgestellt, dass die Platte vom NAS überhaupt nicht erkannt wird.
• Zwischenzeitlich habe ich diverse USB-Geräte an allen drei Ports ausprobiert...es wird keins vom System erkannt.
• Das NAS habe ich zwischenzeitlich neu gestartet und auch mal über Nacht vom Strom abgehängt. Keine Besserung.
• Ich habe aktiv in der betroffenen Zeit nichts an den Einstellungen der DS geändert.

Anbei die Logfiles.

Log-File vom Autorun-Script:

2013-02-08 19:29:46: device 'sdq' - inserted, trying to find mount point
2013-02-08 19:29:50: device 'sdq' - mount point '/volumeUSB2/usbshare' found
2013-02-08 19:29:50: device 'sdq' - script '/volumeUSB2/usbshare/autorun' found, executing
2013-02-08 19:29:51: device '/volumeUSB2/usbshare' - mounting the encrypted file system
2013-02-08 19:30:19: device '/volumeUSB2/usbshare' - local backup 'NAS_Sicherung_usbshare2' started
2013-02-09 09:56:20: device '/volumeUSB2/usbshare' - local backup 'NAS_Sicherung_usbshare2' finished
2013-02-09 09:56:20: device '/volumeUSB2/usbshare' - unmounting the encrypted file system
2013-02-09 09:56:20: device 'sdq' - script '/volumeUSB2/usbshare/autorun' finished, starting unmount
2013-02-09 09:56:25: device 'sdq' - unmounted and ejected

Logfile vom NAS (/var/log/messages), Anstöpseln der Platte am Freitag:

Feb  8 19:29:42 hotplugd: ##### ACTION:add
Feb  8 19:29:42 hotplugd: DEVICE:/proc/bus/usb/001/006
Feb  8 19:29:42 hotplugd: DEVPATH:1-1.2
Feb  8 19:29:42 hotplugd: SUBSYSTEM:usb
Feb  8 19:29:42 hotplugd: external_disk_port_check.c:280 device path should not be NULL
Feb  8 19:29:42 hotplugd: ##### ACTION:add
Feb  8 19:29:42 hotplugd: DEVICE:/proc/bus/usb/001/006
Feb  8 19:29:42 hotplugd: DEVPATH:1-1.2:1.0
Feb  8 19:29:42 hotplugd: SUBSYSTEM:usb
Feb  8 19:29:42 hotplugd: INTERFACE:8/6/80
Feb  8 19:29:46 kernel: [865982.080000] sd 5:0:0:0: [sdq] Assuming drive cache: write through
Feb  8 19:29:46 kernel: [865982.120000] sd 5:0:0:0: [sdq] Assuming drive cache: write through
Feb  8 19:29:46 kernel: [865982.170000] sd 5:0:0:0: [sdq] Assuming drive cache: write through
Feb  8 19:29:47 hotplugd: ##### ACTION:add
Feb  8 19:29:47 hotplugd: DEVNAME:sdq
Feb  8 19:29:47 hotplugd: DEVICE:/proc/bus/usb/001/006
Feb  8 19:29:47 hotplugd: DEVGUID:FAFFFFF0FDF2FFFDFF8273340
Feb  8 19:29:47 hotplugd: DEVPATH:sdq
Feb  8 19:29:47 hotplugd: SUBSYSTEM:block
Feb  8 19:29:47 hotplugd: PHYSDEVPATH:/devices/platform/orion-ehci.0/usb1/1-1/1-1.2/1-1.2:1.0/host5/target5:0:0/5:0:0:0
Feb  8 19:29:47 hotplugd: hotplugd.c:835 ##### complete device hotplug!!
Feb  8 19:29:47 hotplugd: hotplugd.c (1434) ==== USB disk [sdq] plugged in ====
Feb  8 19:29:47 hotplugd: hotplugd.c:1435 goto USB disk, szDeviceName=sdq
Feb  8 19:29:47 scemd: modules/usbcopy.c:55 USBCopy - Unknown Signal: 12
Feb  8 19:29:48 kernel: [865984.210000] EXT3-fs: sdq1: couldn't mount because of unsupported optional features (240).
Feb  8 19:30:09 kernel: [866005.730000] ecryptfs_parse_options: eCryptfs: unrecognized option [passwd=Schinkenplatte007]
Feb  8 19:30:20 synolocalbkp: backup_record.c:148 SLIBCFileSetSection() BACKUP NAS_Sicherung_usbshare2 failed, synoerr=[0x2000]
Feb  8 19:30:20 synolocalbkp: backup_record.c:179 record_updat_waiting() failed.
Feb  8 19:55:23 kernel: [867520.000000] usb 1-1.2: lock for hub EH
Feb  8 19:55:23 kernel: [867520.040000] hub is performing EH
Feb  8 19:55:24 kernel: [867520.190000] usb 1-1.2: unlock for hub EH

Logfile vom NAS (/var/log/messages), Backup schlägt fehl am Samstag:

Feb  9 09:56:17 synolocalbkp: localbkp_copy_file.c:136 read file /volume1/*************Dateiname rausgeschnitten************* errno=[5/Input/output error]
Feb  9 09:56:18 synolocalbkp: backup_record.c:230 SLIBCFileRemoveSection() BACKUP NAS_Sicherung_usbshare2 failed.
Feb  9 09:56:18 synolocalbkp: backup_record.c:258 record_updat_waiting() failed.
Feb  9 09:56:27 hotplugd: ##### ACTION:remove
Feb  9 09:56:27 hotplugd: DEVNAME:sdq
Feb  9 09:56:27 hotplugd: DEVICE:/proc/bus/usb/001/006
Feb  9 09:56:27 hotplugd: DEVPATH:sdq
Feb  9 09:56:27 hotplugd: SUBSYSTEM:block
Feb  9 09:56:27 hotplugd: PHYSDEVPATH:/devices/platform/orion-ehci.0/usb1/1-1/1-1.2/1-1.2:1.0/host5/target5:0:0/5:0:0:0
Feb  9 09:56:27 hotplugd: hotplugd.c (1453) ==== USB disk [sdq] plugged out====
Feb  9 09:56:27 hotplugd: SYNOReadOneSectorFromDev(56): failed to open device [/dev/sdq] (errno = 6)
Feb  9 09:56:27 hotplugd: SYNOReadOneSectorFromDev(56): failed to open device [/dev/sdq] (errno = 6)
Feb  9 09:56:27 hotplugd: usbbkp_is_dev_bkp_disk.c:85 SYNOReadOneSectorFromDev failed. szDevPath=[sdq], errno=[0x0900]
Feb  9 09:56:27 hotplugd: volume_parts_info_get_by_dev.c:318 failed to get disk '/dev/sdq' size

Logfile vom NAS (/var/log/messages), Montag, ich stöpsel diverse USB-Geräte an, Neustart derzeit nicht möglich, da Datenzugriff auf die DS läuft:

Feb 11 08:56:26 hotplugd: DEVICE:/proc/bus/usb/001/006
Feb 11 08:56:26 hotplugd: DEVPATH:1-1.2:1.0
Feb 11 08:56:26 hotplugd: SUBSYSTEM:usb
Feb 11 08:56:26 hotplugd: INTERFACE:8/6/80
Feb 11 08:56:26 hotplugd: ##### ACTION:remove
Feb 11 08:56:26 hotplugd: DEVICE:/proc/bus/usb/001/006
Feb 11 08:56:26 hotplugd: DEVPATH:1-1.2
Feb 11 08:56:26 hotplugd: SUBSYSTEM:usb
Feb 11 08:56:54 kernel: [1087210.360000] hub 1-1:1.0: Cannot enable port 2.  Maybe the USB cable is bad?
Feb 11 08:56:57 kernel: [1087213.360000] hub 1-1:1.0: hub_port_status failed (err = -71)
Feb 11 08:56:57 kernel: [1087213.390000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.430000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.470000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.510000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.510000] hub 1-1:1.0: Cannot enable port 2.  Maybe the USB cable is bad?
Feb 11 08:56:57 kernel: [1087213.550000] hub 1-1:1.0: cannot disable port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.680000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.710000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.750000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.790000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.820000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.830000] hub 1-1:1.0: Cannot enable port 2.  Maybe the USB cable is bad?
Feb 11 08:56:57 kernel: [1087213.870000] hub 1-1:1.0: cannot disable port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.910000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.940000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:58 kernel: [1087213.980000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:58 kernel: [1087214.020000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:58 kernel: [1087214.050000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:58 kernel: [1087214.060000] hub 1-1:1.0: Cannot enable port 2.  Maybe the USB cable is bad?
Feb 11 08:56:58 kernel: [1087214.100000] hub 1-1:1.0: cannot disable port 2 (err = -71)
Feb 11 08:56:58 kernel: [1087214.100000] hub 1-1:1.0: unable to enumerate USB device on port 2
Feb 11 08:56:58 kernel: [1087214.140000] hub 1-1:1.0: cannot disable port 2 (err = -71)
Feb 11 08:56:58 kernel: [1087214.180000] hub 1-1:1.0: hub_port_status failed (err = -71)
Feb 11 08:56:59 kernel: [1087215.270000] usb 1-1: device descriptor read/64, error -71
Feb 11 08:56:59 kernel: [1087215.590000] usb 1-1: device descriptor read/64, error -71
Feb 11 08:56:59 hotplugd: ##### ACTION:remove
Feb 11 08:56:59 hotplugd: DEVICE:/proc/bus/usb/001/002
Feb 11 08:56:59 hotplugd: DEVPATH:1-1:1.0
Feb 11 08:56:59 hotplugd: SUBSYSTEM:usb
Feb 11 08:56:59 hotplugd: INTERFACE:9/0/0
Feb 11 08:56:59 hotplugd: ##### ACTION:remove
Feb 11 08:56:59 hotplugd: DEVICE:/proc/bus/usb/001/002
Feb 11 08:56:59 hotplugd: DEVPATH:1-1
Feb 11 08:56:59 hotplugd: SUBSYSTEM:usb
Feb 11 08:57:01 kernel: [1087217.550000] ata1: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
Feb 11 08:57:01 kernel: [1087217.560000] ata1: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
Feb 11 08:57:01 kernel: [1087217.570000] ata1: SError: { 10B8B Dispar }
Feb 11 08:57:01 kernel: [1087217.580000] ata2: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
Feb 11 08:57:01 kernel: [1087217.580000] ata2: edma_err_cause=00000020 pp_flags=00000003, SError=00180000
Feb 11 08:57:01 kernel: [1087217.590000] ata2: SError: { 10B8B Dispar }
Feb 11 08:57:03 kernel: [1087219.280000] hub 1-0:1.0: unable to enumerate USB device on port 1
Feb 11 09:00:53 kernel: [1087449.430000] __ratelimit: 1 callbacks suppressed
Feb 11 09:01:40 kernel: [1087496.730000] __ratelimit: 11 callbacks suppressed

...weiter im nächsten Post...

 

[nosi]

und der Rest:

Logfile vom NAS (/var/log/messages), Dienstag Neustart und Check mit USB-Platte. Funktioniert noch immer nicht:

eb 12 09:17:47 PkgSynoMan.cgi: PkgSynoMan.cpp:893 Failed to mkdir pkglist.tmp, File exists
Feb 12 18:16:45 scemd: scemd.c:287 receive SIGTERM
Feb 12 18:16:49 root: /usr/syno/etc/rc.d/S98findhostd.sh stop findhostd
killall: synolunbkp: no process killed
Feb 12 18:17:13 syslogd exiting
Feb 12 18:18:21 syslogd started: BusyBox v1.16.1
Feb 12 18:18:23 spacetool: spacetool.c:2470 [Info] Activate all VG
Feb 12 18:18:25 synovspace: vspace_wrapper_load_all.c:75 [INFO] The mount device path of space [/volume1] is [/dev/md2]
Feb 12 18:18:26 s42_synocheckgrp: SYNOICheckLocalGrp(315): replace szBuf=[guests:x:65536:gast,gast2,gast3] with szOutBuf=[guests:x:65536:gast2,gast3,gast]!
Feb 12 18:18:26 s42_synocheckgrp: SYNOICheckLocalGrp(357): Fix Local group files.
Feb 12 18:18:35 scemd: scemd.c:154 fan_type=3, raid_type=1, led_type=1, thermal_type=2, diskled_ctrl_type=1, auto_poweron_type=1, dual_power_type=1, usbcopy_type=1, fan_number=1, eunit_pwron_type=0, pis_type=1, rtc_type=2, lcm_type=2, wifi_wps_type=0
Feb 12 18:18:36 scemd: modules/fan_speed_adjust_common.c:118 Type: INTERNAL Fan Mode: LOW 
Feb 12 18:18:36 scemd: modules/raid_sys_volume_check.c:150 MD0 active disks 1, designed disks 2 
Feb 12 18:18:36 scemd: modules/raid_sys_volume_check.c:150 MD1 active disks 2, designed disks 2 
Feb 12 18:18:36 scemd: modules/disk_hibernation.c:1802 Force hibernation enable, idle minutes 0
Feb 12 18:18:36 scemd: modules/disk_hibernation.c:1826 Eunit Deep sleep timer 0
Feb 12 18:18:37 scemd: disk/disk_config_all.c:124 apply /usr/syno/bin/hdparm -B 254  /dev/sda 1>/dev/null 2>&1
Feb 12 18:18:37 scemd: disk/disk_config_all.c:124 apply /usr/syno/bin/hdparm -B 254  /dev/sdb 1>/dev/null 2>&1
Feb 12 18:18:37 scemd: scemd.c:154 fan_type=3, raid_type=1, led_type=1, thermal_type=2, diskled_ctrl_type=1, auto_poweron_type=1, dual_power_type=1, usbcopy_type=1, fan_number=1, eunit_pwron_type=0, pis_type=1, rtc_type=2, lcm_type=2, wifi_wps_type=0
Feb 12 18:18:37 scemd: scemd.c:353 WIFI/WPS button is not support on this model.
Feb 12 18:18:37 scemd: modules/scemd_connector.c:103 scemd connector thread start.
Feb 12 18:18:38 synoprint: printer_enable_ext.c:488 delete printer failed: no bus id
Feb 12 18:18:39 syno_hdd_util: Model:[HD204UI], Firmware:[1AQ10001], S/N:[S2H7J1BZ912475] in [/dev/sdb] is not ssd
Feb 12 18:18:40 syno_hdd_util: Model:[HD204UI], Firmware:[1AQ10001], S/N:[S2H7J1BZ912535] in [/dev/sda] is not ssd
Feb 12 18:18:41 synocheckshare: Fix shares in smb.conf.
Feb 12 18:18:42 synocheckshare: service_disable_set.c(68)Not defined date : id=4
Feb 12 18:18:47 synousbdisk: RCClean succeeded
Feb 12 18:18:47 synosata: synosata.c:152 no external sata devices granted
Feb 12 18:18:49 hotplugd: hotplugd.c:1033 failed get usb status from usb config, DEVICE=/proc/bus/usb/001/001, usbid=1d6b:0002:orion-ehci.0
Feb 12 18:18:49 hotplugd: ##### ACTION:add
Feb 12 18:18:49 hotplugd: DEVICE:/proc/bus/usb/001/001
Feb 12 18:18:49 hotplugd: DEVPATH:usb1
Feb 12 18:18:49 hotplugd: SUBSYSTEM:usb
Feb 12 18:18:49 hotplugd: hotplugd.c:807 Fail to recognize usb DEVNAME=, DEVPATH=usb1
Feb 12 18:18:49 hotplugd: hotplugd.c:1331 failed to setup usb config, (DEVPATH, DEVICE, ACTION, DEVNAME, INTERFACE)=(usb1, /proc/bus/usb/001/001, add, , )
Feb 12 18:18:50 hotplugd: hotplugd.c:1033 failed get usb status from usb config, DEVICE=/proc/bus/usb/001/001, usbid=1d6b:0002:orion-ehci.0
Feb 12 18:18:50 hotplugd: ##### ACTION:add
Feb 12 18:18:50 hotplugd: DEVICE:/proc/bus/usb/001/001
Feb 12 18:18:50 hotplugd: DEVPATH:1-0:1.0
Feb 12 18:18:50 hotplugd: SUBSYSTEM:usb
Feb 12 18:18:50 hotplugd: INTERFACE:9/0/0
Feb 12 18:18:50 ddnsd: main(ddnsd.c:3006):  not enable DDNS, shutdown daemon
Feb 12 18:18:50 heartbeatd: heartbeatd.c:164 DDNS does not enable, skip starting
Feb 12 18:20:36 scemd: scemd.c:413 stop manutild.
Feb 12 18:35:42 scemd: scemd.c:287 receive SIGTERM
Feb 12 18:35:46 root: /usr/syno/etc/rc.d/S98findhostd.sh stop findhostd
killall: synolunbkp: no process killed
Feb 12 18:36:10 umount: Kill the process "/opt/bin/mc" with /opt/bin/mc.
Feb 12 18:36:11 syslogd exiting

Hat jemand eine Idee, was hier schief läuft? Speziell der Log-Eintrag vom Montag Morgen macht mich stutzig:

Feb 11 08:56:54 kernel: [1087210.360000] hub 1-1:1.0: Cannot enable port 2.  Maybe the USB cable is bad?
Feb 11 08:56:57 kernel: [1087213.360000] hub 1-1:1.0: hub_port_status failed (err = -71)
Feb 11 08:56:57 kernel: [1087213.390000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.430000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.470000] hub 1-1:1.0: cannot reset port 2 (err = -71)
Feb 11 08:56:57 kernel: [1087213.510000] hub 1-1:1.0: cannot reset port 2 (err = -71)

nosi

 

[Merthos]

Du kannst das auorun-Paket mal stoppen, dann hängt es nicht mehr in dem "Einhängen-Prozess" mit drin. Anderes Kabel probiert?

 

[nosi]

Hallo Merthos,

das autorun-Paket ist gestoppt. Keine Änderung.

Das Kabel kann es nicht sein, denn auch USB-Sticks, die vorher liefen, funktionieren (direkt ohne Verlängerungskabel eingesteckt) nicht... :-(

 

[Merthos]

Tja, dann würde ich mit einer anderen Platte probieren, ob ein Reset der FW was bringt.

 

[nosi]

Okay, ich warte mal ab, was der Support schreibt, den habe ich nämlich parallel angeschrieben.

Eine Idee von mir war, mal die Firmware upzudaten (da ich eh nicht die aktuelle habe). Ich meine im autorun-Thread gelesen zu haben, dass sich bei einer neueren Version wieder irgendwelche Zugriffe geändert haben und es deswegen zu Problemen mit dem Autorun-Paket kommen kann. Die DS schlägt ein Update auf 4.1 2668 vor. Geht diese Version noch problemlos mit dem autorun-Paket?

 

[Merthos]

Mir ist nichts Gegenteiliges bekannt.

 

[nosi]

Tja, dann würde ich mit einer anderen Platte probieren, ob ein Reset der FW was bringt.

Also die neuere Firmware habe ich installiert, das bringt leider keine Änderung. Der Synology-Support hat sich noch nicht gemeldet.

Da ich keine weitere Festplatte herumliegen habe, die ich Testweise einbauen könnte, hier ein paar allgemeine Fragen:
Bootet die Diskstation auch ohne Festplatte? Das System liegt doch auf einem Flash-Speicher, oder? Gibt es eine Möglichkeit, das System vorher komplett zu sichern, z.B. per SSH alle Daten auf die eingebaute Platte schieben??

Wenn ich die Konfiguration gesichert habe und die Firmware resette (btw: geht das über die DSM-Software), sind nachher wohl nur alle Third-Party-Apps weg, oder? Ich habe nämlich noch ein paar php-Sachen am Laufen, die sollte ich dann wohl auch sichern...

 

[nosi]

Also um die Sache mal aufzuklären: Der Support hat mir anhand dem angeforderten Kernel-Logfile (debug.dat) mitgeteilt, dass das Motherboard hinüber ist. Schade, die Garantie ist vor 5 Monaten abgelaufen...