[Search for users] [Overall Top Noters] [List of all Conferences] [Download this site]

Conference decwet::networker

Title:	NetWorker
Notice:	kits - 12-14, problem reporting - 41.*, basics 1-100
Moderator:	DECWET::RANDALL.com::lenox

Created:	Thu Oct 10 1996
Last Modified:	Fri Jun 06 1997
Last Successful Update:	Fri Jun 06 1997
Number of topics:	750
Total number of notes:	3361

711.0. "HSM: I/O error occur at recalling file" by KTOV11::TAKEUCHI (Hideto Takeuchi/OS4/PSC/Japan) Sun May 25 1997 23:14

The I/O error occured at recall in following operation. What wrong in this
operation.

1) pre-migrate file	start now in 'group' window. confirm load to tape in
			'index' window.

2) migrate file		set 'high/low water mark' to lower. replaced to stub.

3) recall file		# cat file. succeeded. the file is real entity.

4) migrate file		same 2). replaced to stub again.

5) recall file		# cat file.  But I/O error occur.

6) kill browser		# kill -TERM xxxx(nsriba process id)

7) recall file		# cat file. succeeded.


Why I/O error occur at 5)?  

Thanks,
hideto

T.R	Title	User	Personal Name	Date	Lines
711.1	We'll need a bit more information please...	DECWET::SDY	Support Novice...seeking enlightenment	`Mon May 26 1997 17:42`	15
	In step 5, where you mention the i/o error -- did you check before you tried step 6 to see if the file was successfully recalled? it might have been a result of cat "timing out" before the file fully appeared, if this was the case, it could be a result of a busy network or just a delay in the tape retrieval. In any case, could you send me the exact error message, as well as the portion of the /nsr/logs/daemon.log and /nsr/logs/messages that show the I/O error, and the attempted recalls of the file? Also I'll need to know your system setup (is this a remote client? jukebox? server hardware config.. etc) thanks, steve.
711.2	detail description	KTOV11::TAKEUCHI	Hideto Takeuchi/OS4/PSC/Japan	`Mon May 26 1997 21:36`	276
	My system setup is following, NetWorker Server/Client ktoa02.osa.dec.com(Not Single Server) DEC3000/400, DU4.0A Group hsm Auto start use 'start now' only Migration hsm Group hsm SaveSets /mhayashi2/hsm Water mark describe after Last access time not set Minimum file size not set File owner not set File group not set Preserve not set Pool hsm Group hsm Client not set SaveSets /mhayashi2/hsm Device /dev/nrmt1h Volume labeling Device /dev/nrmt1h Pool hsm I explain result of doing test with log. Step 0): Confirm environment of doing test. ------------------------------------------------------------------------------ # pwd /mhayashi2/hsm # df -k . Filesystem 1024-blocks Used Available Capacity Mounted on user_domain#mhayashi2 649584 252192 391536 40% /mhayashi2 # ls -l total 35664 -rwxr-xr-x 1 root system 12172752 May 27 10:08 1 -rwxr-xr-x 1 root system 12172752 May 27 10:08 2 -rwxr-xr-x 1 root system 12172752 May 27 10:09 3 ------------------------------------------------------------------------------ Step 1): pre-migrate file Start now in 'hsm' group in group window. confirm load to tape in 'index' window. When doing backup file index to poll 'default' after pre-migration , I stopped it by push stop button in Group Contorol window, because I have only one tape device for pool 'hsm'. Step 2): migrate file Set 'High water mark' to 35, and 'Low water mark' to 30. push Apply button. Result is following, All file are replaced to stub. ------------------------------------------------------------------------------ # ls -l total 0 lrwxr-xr-x 1 root system 86 May 27 10:15 1 -> /ib/ktoa02.osa.dec.co m:ktoa02.osa.dec.com#migrated/00000655.ffffffff8704bfbd@864695556 lrwxr-xr-x 1 root system 86 May 27 10:15 2 -> /ib/ktoa02.osa.dec.co m:ktoa02.osa.dec.com#migrated/00000649.ffffffff8704bfbd@864695556 lrwxr-xr-x 1 root system 86 May 27 10:15 3 -> /ib/ktoa02.osa.dec.co m:ktoa02.osa.dec.com#migrated/00000658.ffffffff8704bfbd@864695556 # df -k . Filesystem 1024-blocks Used Available Capacity Mounted on user_domain#mhayashi2 649584 216528 427200 34% /mhayashi2 ------------------------------------------------------------------------------ Step 3): recall file Cat two files named '1' and '2'. Cat is finish successfully. Stub is replaced original file(confirm by size only). ------------------------------------------------------------------------------ # cat 1 > /dev/null # df -k . Filesystem 1024-blocks Used Available Capacity Mounted on user_domain#mhayashi2 649584 228416 415312 36% /mhayashi2 # ls -l total 11888 -rwxr-xr-x 1 root system 12172752 May 27 10:08 1 lrwxr-xr-x 1 root system 86 May 27 10:15 2 -> /ib/ktoa02.osa.dec.c om:ktoa02.osa.dec.com#migrated/00000649.ffffffff8704bfbd@864695556 lrwxr-xr-x 1 root system 86 May 27 10:15 3 -> /ib/ktoa02.osa.dec.c om:ktoa02.osa.dec.com#migrated/00000658.ffffffff8704bfbd@864695556 # cat 2 > /dev/null # df -k . Filesystem 1024-blocks Used Available Capacity Mounted on user_domain#mhayashi2 649584 240304 403424 38% /mhayashi2 # ls -l total 23776 -rwxr-xr-x 1 root system 12172752 May 27 10:08 1 -rwxr-xr-x 1 root system 12172752 May 27 10:08 2 lrwxr-xr-x 1 root system 86 May 27 10:15 3 -> /ib/ktoa02.osa.dec.c om:ktoa02.osa.dec.com#migrated/00000658.ffffffff8704bfbd@864695556 ------------------------------------------------------------------------------ ) While cat file named '1' and '2', disk usage has been over High water mark, but migration have not occur. Is this problem? Step 4): migrate file Set 'High water mark' to 36, and 'Low water mark' to 30. push Apply button. Result is following, File named '1' and '2' are replaced to stub again. ------------------------------------------------------------------------------ # ls -l total 0 lrwxr-xr-x 1 root system 86 May 27 10:20 1 -> /ib/ktoa02.osa.dec.co m:ktoa02.osa.dec.com#migrated/00000655.ffffffff8704bfbd@864695556 lrwxr-xr-x 1 root system 86 May 27 10:20 2 -> /ib/ktoa02.osa.dec.co m:ktoa02.osa.dec.com#migrated/00000649.ffffffff8704bfbd@864695556 lrwxr-xr-x 1 root system 86 May 27 10:15 3 -> /ib/ktoa02.osa.dec.co m:ktoa02.osa.dec.com#migrated/00000658.ffffffff8704bfbd@864695556 # df -k . Filesystem 1024-blocks Used Available Capacity Mounted on user_domain#mhayashi2 649584 216528 427200 34% /mhayashi2 ------------------------------------------------------------------------------ Step 5): recall file Cat all files. Files named '1' and '2' occur I/O error, don't recall. File named '3' don't occur error, because it is first recall for file '3' ------------------------------------------------------------------------------ # cat 1 > /dev/null cat: 1 : I/O error # cat 2 > /dev/null cat: 2 : I/O error # cat 3 > /dev/null ------------------------------------------------------------------------------ Step 6): kill browser Send TERM signal to nsriba process. ------------------------------------------------------------------------------ # ps ax \| grep nsr 539 ?? S 28:45.26 /usr/bin/nsrd 553 ?? I 1:07.35 /usr/bin/nsrexecd 554 ?? I 0:33.33 /usr/bin/nsrib -M -s ktoa02.osa.dec.com 574 ?? I 1:29.75 /usr/bin/nsrmmdbd 580 ?? S 1:13.36 /usr/bin/nsrindexd 587 ?? I < 4:36.47 /usr/bin/nsrmmd -n 1 9449 ?? I < 8:44.07 /usr/bin/nsrmmd -n 2 17760 ?? S 0:25.29 /usr/bin/nsriba -s ktoa02.osa.dec.com -c ktoa02. osa.dec.com -T Rtmp.ktoa02.osa.dec.com.migrated -t 05-27-97 10:16:29 -N /ib/ktoa 02.osa.dec.com:ktoa02.osa.dec.com#migrated -I migrated /ib/ktoa02.osa.dec.com:kt oa02.osa.dec.com#migrated@now 17822 ?? I 0:00.25 /usr/bin/ansrd ktoa02.osa.dec.com:migration brow ser (pid17760@/ib/ktoa02.osa.dec.com:ktoa02.osa.d recovering 17997 ttyp1 S + 0:00.04 grep nsr # kill -TERM 17760 # ps ax \| grep nsr 539 ?? S 28:45.46 /usr/bin/nsrd 553 ?? S 1:07.35 /usr/bin/nsrexecd 554 ?? S 0:33.34 /usr/bin/nsrib -M -s ktoa02.osa.dec.com 574 ?? S 1:29.75 /usr/bin/nsrmmdbd 580 ?? S 1:13.38 /usr/bin/nsrindexd 587 ?? I < 4:36.47 /usr/bin/nsrmmd -n 1 9449 ?? I < 8:44.07 /usr/bin/nsrmmd -n 2 18001 ttyp1 S + 0:00.03 grep nsr ------------------------------------------------------------------------------ Step7): recall file Cat files named '1' and '2' again, finished successfully. ------------------------------------------------------------------------------ # ls -l total 11888 lrwxr-xr-x 1 root system 86 May 27 10:20 1 -> /ib/ktoa02.osa.dec.c om:ktoa02.osa.dec.com#migrated/00000655.ffffffff8704bfbd@864695556 lrwxr-xr-x 1 root system 86 May 27 10:20 2 -> /ib/ktoa02.osa.dec.c om:ktoa02.osa.dec.com#migrated/00000649.ffffffff8704bfbd@864695556 -rwxr-xr-x 1 root system 12172752 May 27 10:09 3 # cat 1 > /dev/null # cat 2 > /dev/null # ls -l total 35664 -rwxr-xr-x 1 root system 12172752 May 27 10:08 1 -rwxr-xr-x 1 root system 12172752 May 27 10:08 2 -rwxr-xr-x 1 root system 12172752 May 27 10:09 3 # ------------------------------------------------------------------------------ >In any case, could you send me the exact error message, as well as the portion >of the /nsr/logs/daemon.log and /nsr/logs/messages that show the I/O error, and >the attempted recalls of the file? daemon.log and messages are following, daemon.log -- 5/27/97 10:07:47 nsrd: ktoa02.osa.dec.com:migration browser (pid17762@/ib/ktoa02.osa.dec.com:ktoa02.osa.d browsing 5/27/97 10:10:34 nsrd: ktoa02.osa.dec.com:migration browser (pid17762@/ib/ktoa02.osa.dec.com:ktoa02.osa.d done browsing 5/27/97 10:10:49 nsrd: /dev/nrmt1h verify label operation in progress 5/27/97 10:11:23 nsrd: /dev/nrmt1h label operation in progress 5/27/97 10:11:30 nsrd: media info: 4mm 4GB tape ktoa02.osa.dec.com.migrate.002 will be over-written 5/27/97 10:12:26 savegrp: Client ktoa02.osa.dec.com for group hsm has no 'SS Consolidation' attribute; defaulting to 'No' 5/27/97 10:12:26 savegrp: Client ktoa02.osa.dec.com for group hsm has no 'SS Consolidation' attribute; defaulting to 'No' 5/27/97 10:12:26 nsrd: savegroup info: starting hsm (with 1 client) 5/27/97 10:12:51 nsrd: ktoa02.osa.dec.com:/mhayashi2/hsm migrating to pool 'hsm' (ktoa02.osa.dec.com.migrate.002) 5/27/97 10:13:50 nsrd: ktoa02.osa.dec.com:/mhayashi2/hsm done migrating to pool 'hsm' (ktoa02.osa.dec.com.migrate.002) 34 MB 5/27/97 10:13:54 nsrd: media info: suggest mounting ktoa02.osa.dec.com.001 for writing to pool 'Default' 5/27/97 10:13:55 nsrd: media waiting event: backup to pool 'Default' waiting for 1 writable backup tape 5/27/97 10:14:11 savegrp: group hsm aborted. 5/27/97 10:14:11 savegrp: killing pid 16733 5/27/97 10:14:11 nsrexecd: failed to write NUL handshake on s (4): Broken pipe 5/27/97 10:14:13 nsrd: savegroup alert: hsm aborted, 1 client (ktoa02.osa.dec.com Failed) 5/27/97 10:14:25 nsrd: media event cleared: backup to pool 'Default' waiting for 1 writable backup tape 5/27/97 10:14:25 nsrd: ktoa02.osa.dec.com:/usr/var/nsr/index/ktoa02.osa.dec.com done saving 5/27/97 10:14:25 nsrd: inconsistency in mmd 1 authorization structure, state MM_MODE_WRITING(1), number of authorized and active sessions is zero, initializing structure 5/27/97 10:15:39 nsrd: migration notice: Migration of ktoa02.osa.dec.com: /mhayashi2/hsm completed 5/27/97 10:15:41 nsrd: migration critical: ktoa02.osa.dec.com:/mhayashi2/hsm is 34 percent full (desired 30 percent) 5/27/97 10:16:30 nsrd: ktoa02.osa.dec.com:migration browser (pid17760@/ib/ktoa02.osa.dec.com:ktoa02.osa.d browsing 5/27/97 10:16:34 nsrd: media info event: 4mm 4GB tape ktoa02.osa.dec.com.migrate.002 will be needed 5/27/97 10:16:45 nsrd: media event cleared: confirmed mount of ktoa02.osa.dec.com.migrate.002 on /dev/nrmt1h 5/27/97 10:16:46 nsrd: ktoa02.osa.dec.com:/mhayashi2/hsm (5/27/97) starting read from ktoa02.osa.dec.com.migrate.002 of 12 MB 5/27/97 10:17:03 nsrd: ktoa02.osa.dec.com:/mhayashi2/hsm (5/27/97) done reading 12 MB 5/27/97 10:18:56 nsrd: media info event: 4mm 4GB tape ktoa02.osa.dec.com.migrate.002 will be needed 5/27/97 10:19:03 nsrd: media event cleared: confirmed mount of ktoa02.osa.dec.com.migrate.002 on /dev/nrmt1h 5/27/97 10:19:04 nsrd: ktoa02.osa.dec.com:/mhayashi2/hsm (5/27/97) starting read from ktoa02.osa.dec.com.migrate.002 of 12 MB 5/27/97 10:19:28 nsrd: ktoa02.osa.dec.com:/mhayashi2/hsm (5/27/97) done reading 12 MB 5/27/97 10:20:36 nsrd: migration notice: Migration of ktoa02.osa.dec.com: /mhayashi2/hsm completed 5/27/97 10:20:38 nsrd: migration critical: ktoa02.osa.dec.com:/mhayashi2/hsm is 34 percent full (desired 30 percent) 5/27/97 10:21:19 nsrd: media info event: 4mm 4GB tape ktoa02.osa.dec.com.migrate.002 will be needed 5/27/97 10:21:32 nsrd: media event cleared: confirmed mount of ktoa02.osa.dec.com.migrate.002 on /dev/nrmt1h 5/27/97 10:21:32 nsrd: ktoa02.osa.dec.com:/mhayashi2/hsm (5/27/97) starting read from ktoa02.osa.dec.com.migrate.002 of 12 MB 5/27/97 10:22:28 nsrd: ktoa02.osa.dec.com:/mhayashi2/hsm (5/27/97) done reading 12 MB 5/27/97 10:23:29 nsrd: ktoa02.osa.dec.com:migration browser (pid17760@/ib/ktoa02.osa.dec.com:ktoa02.osa.d done browsing 5/27/97 10:23:46 nsrd: ktoa02.osa.dec.com:migration browser (pid17897@/ib/ktoa02.osa.dec.com:ktoa02.osa.d browsing 5/27/97 10:23:49 nsrd: media info event: 4mm 4GB tape ktoa02.osa.dec.com.migrate.002 will be needed 5/27/97 10:24:06 nsrd: media event cleared: confirmed mount of ktoa02.osa.dec.com.migrate.002 on /dev/nrmt1h 5/27/97 10:24:06 nsrd: ktoa02.osa.dec.com:/mhayashi2/hsm (5/27/97) starting read from ktoa02.osa.dec.com.migrate.002 of 12 MB 5/27/97 10:24:23 nsrd: ktoa02.osa.dec.com:/mhayashi2/hsm (5/27/97) done reading 12 MB 5/27/97 10:25:00 nsrd: media info event: 4mm 4GB tape ktoa02.osa.dec.com.migrate.002 will be needed 5/27/97 10:25:06 nsrd: media event cleared: confirmed mount of ktoa02.osa.dec.com.migrate.002 on /dev/nrmt1h 5/27/97 10:25:06 nsrd: ktoa02.osa.dec.com:/mhayashi2/hsm (5/27/97) starting read from ktoa02.osa.dec.com.migrate.002 of 12 MB 5/27/97 10:25:31 nsrd: ktoa02.osa.dec.com:/mhayashi2/hsm (5/27/97) done reading 12 MB messages -- May 27 10:11:31 ktoa02 syslog: NetWorker media: (info) 4mm 4GB tape ktoa02.osa.dec.com.migrate.002 will be over-written May 27 10:12:26 ktoa02 syslog: NetWorker Savegroup: (info) starting hsm (with 1 client) May 27 10:13:54 ktoa02 syslog: NetWorker media: (info) suggest mounting ktoa02.osa.dec.com.001 for writing to pool 'Default' May 27 10:13:55 ktoa02 syslog: NetWorker media: (waiting) backup to pool 'Default' waiting for 1 writable backup tape May 27 10:14:12 ktoa02 syslog: NetWorker Savegroup: (alert) hsm aborted, 1 client (ktoa02.osa.dec.com Failed) May 27 10:14:12 ktoa02 syslog: Start time: Tue May 27 10:12:25 1997 May 27 10:14:12 ktoa02 syslog: End time: Tue May 27 10:14:11 1997 May 27 10:14:12 ktoa02 syslog: May 27 10:14:12 ktoa02 syslog: --- Unsuccessful Save Sets --- May 27 10:14:12 ktoa02 syslog: May 27 10:14:12 ktoa02 syslog: ktoa02.osa.dec.com:index aborted May 27 10:14:12 ktoa02 syslog: May 27 10:14:12 ktoa02 syslog: --- Successful Save Sets --- May 27 10:14:12 ktoa02 syslog: May 27 10:14:12 ktoa02 syslog: ktoa02.osa.dec.com: /mhayashi2/hsm level=migration, 36 MB 00:01:13 3 files May 27 10:14:12 ktoa02 syslog: May 27 10:15:39 ktoa02 syslog: NetWorker Migration: (notice) Migration of ktoa02.osa.dec.com: /mhayashi2/hsm completed May 27 10:15:39 ktoa02 syslog: May 27 10:15:39 ktoa02 syslog: Files migrated this run (summary at end): May 27 10:15:39 ktoa02 syslog: /mhayashi2/hsm/3 May 27 10:15:39 ktoa02 syslog: /mhayashi2/hsm/2 May 27 10:15:39 ktoa02 syslog: /mhayashi2/hsm/1 May 27 10:15:39 ktoa02 syslog: nsrmig: /mhayashi2/hsm 36 MB 00:00:02 3 files May 27 10:15:39 ktoa02 syslog: NetWorker Migration: (critical) ktoa02.osa.dec.com:/mhayashi2/hsm is 34 percent full (desired 30 percent) May 27 10:15:39 ktoa02 syslog: Migration run completed but was unable to find enough candidate files for May 27 10:15:39 ktoa02 syslog: migration. Consider making migration criteria more strict. May 27 10:16:34 ktoa02 syslog: NetWorker media: (info) 4mm 4GB tape ktoa02.osa.dec.com.migrate.002 will be needed May 27 10:18:56 ktoa02 syslog: NetWorker media: (info) 4mm 4GB tape ktoa02.osa.dec.com.migrate.002 will be needed May 27 10:20:36 ktoa02 syslog: NetWorker Migration: (notice) Migration of ktoa02.osa.dec.com: /mhayashi2/hsm completed May 27 10:20:36 ktoa02 syslog: May 27 10:20:36 ktoa02 syslog: Files migrated this run (summary at end): May 27 10:20:36 ktoa02 syslog: /mhayashi2/hsm/2 May 27 10:20:36 ktoa02 syslog: /mhayashi2/hsm/1 May 27 10:20:37 ktoa02 syslog: nsrmig: /mhayashi2/hsm 24 MB 00:00:01 2 files May 27 10:20:37 ktoa02 syslog: NetWorker Migration: (critical) ktoa02.osa.dec.com:/mhayashi2/hsm is 34 percent full (desired 30 percent) May 27 10:20:37 ktoa02 syslog: Migration run completed but was unable to find enough candidate files for May 27 10:20:37 ktoa02 syslog: migration. Consider making migration criteria more strict. May 27 10:21:19 ktoa02 syslog: NetWorker media: (info) 4mm 4GB tape ktoa02.osa.dec.com.migrate.002 will be needed May 27 10:23:49 ktoa02 syslog: NetWorker media: (info) 4mm 4GB tape ktoa02.osa.dec.com.migrate.002 will be needed May 27 10:25:00 ktoa02 syslog: NetWorker media: (info) 4mm 4GB tape ktoa02.osa.dec.com.migrate.002 will be needed Thanks, hideto
711.3	we'll take this off line	DECWET::SDY	Support Novice...seeking enlightenment	`Tue May 27 1997 17:32`	8
	This may be more involved, I'm taking this to direct email instead and will post a summary when done. Hideto, expect an email from me, if you don't see it by 5/28 ping me to make sure it didn't get lost. steve.