Coda File System

Still wrestling clog, local login only - lotsa logs, no errors found

From: Brad Clements <bkc_at_murkworks.com>
Date: Mon, 22 Jan 2001 14:17:30 -0500
Clog returns

[bkc_at_eiger include]$ clog
username: bkc
Password: 
Local login only, could not contact venus
[bkc_at_eiger include]$ ctokens

Token held by the Cache Manager:

Local uid: 500

GetLocalTokens error (13)
[bkc_at_eiger include]$ ls /coda
ls: /coda: Permission denied
[bkc_at_eiger include]$ 


--

Fid 7f000000

But root volume is 1000001

Does that matter?

---

I've turned on more tracing, and get this in /var/log/messages

Jan 22 14:09:26 eiger kernel: (do_time_stats,l. 141): time: 0
Jan 22 14:09:26 eiger kernel: (do_time_stats,l. 141): time: 0
Jan 22 14:09:26 eiger kernel: (coda_upcall,l. 732): opc: 9 time: 5 uniq: 14 size: 12
Jan 22 14:09:26 eiger kernel: (coda_upcall,l. 735): ..process 2631 woken up by Venus for req at c54590a0, data at c21ad2c0
Jan 22 14:09:26 eiger kernel: (coda_upcall,l. 749): upcall: (u,o,r) (14, 9, 13) out at c21ad2c0
Jan 22 14:09:26 eiger kernel: (coda_upcall,l. 805): kfreed: 20 at c54590a0.
Jan 22 14:09:26 eiger kernel: (venus_access,l. 507): kfreed: 40 at c21ad2c0.
Jan 22 14:09:26 eiger kernel: Process 2631 leaving venus_access
Jan 22 14:09:26 eiger kernel: (coda_permission,l. 204): fid: (0x7f000000,0x1,0x1), ino: 1025 (mask: 1) error: -13


Error 13 is EPERM, which is the same error I get if I try to ls /coda

Ctokens reports:

GetLocalTokens error 13

And in /var/log/messages

Jan 22 14:11:54 eiger kernel: Process 2638 entered coda_permission
Jan 22 14:11:54 eiger kernel: (coda_cache_check,l. 235): MISS for ino 1025
Jan 22 14:11:54 eiger kernel: (coda_permission,l. 200): mask is 1
Jan 22 14:11:54 eiger kernel: (venus_access,l. 500): kmalloced: 40 at c21adf80.
Jan 22 14:11:54 eiger kernel: Process 2638 entered coda_upcall
Jan 22 14:11:54 eiger kernel: (coda_upcall,l. 698): kmalloced: 20 at c5459120.
Jan 22 14:11:54 eiger kernel: (coda_upcall,l. 714): Proc 2638 wake Venus for(opc,uniq) =(9,16) msg at c5459120.zzz.
Jan 22 14:11:54 eiger kernel: (coda_psdev_read,l. 193): count 8464
Jan 22 14:11:54 eiger kernel: (coda_psdev_write,l. 102): (process,opc,uniq)=(2414,9,16), count 12
Jan 22 14:11:54 eiger kernel: (coda_psdev_write,l. 151): Eureka: uniq 16 on queue!
Jan 22 14:11:54 eiger kernel: (coda_psdev_write,l. 176): Found! Count 12 for (opc,uniq)=(9,16), upc_req at c4c61f5c
Jan 22 14:11:54 eiger kernel: (coda_waitfor_upcall,l. 663): begin: 0.000000, elapsed: 0.000000
Jan 22 14:11:54 eiger kernel: (do_time_stats,l. 141): time: 0
Jan 22 14:11:54 eiger kernel: (do_time_stats,l. 141): time: 0
Jan 22 14:11:54 eiger kernel: (coda_upcall,l. 732): opc: 9 time: 1 uniq: 16 size: 12
Jan 22 14:11:54 eiger kernel: (coda_upcall,l. 735): ..process 2638 woken up by Venus for req at c5459120, data at c21adf80
Jan 22 14:11:54 eiger kernel: (coda_upcall,l. 749): upcall: (u,o,r) (16, 9, 13) out at c21adf80
Jan 22 14:11:54 eiger kernel: (coda_upcall,l. 805): kfreed: 20 at c5459120.
Jan 22 14:11:54 eiger kernel: (venus_access,l. 507): kfreed: 40 at c21adf80.
Jan 22 14:11:54 eiger kernel: Process 2638 leaving venus_access
Jan 22 14:11:54 eiger kernel: (coda_permission,l. 204): fid: (0x7f000000,0x1,0x1), ino: 1025 (mask: 1) error: -13

Interestingly, I am able to change the account password with au.

Also, I have another machine and that machine also cannot access my 
server.

However *both* machines *can* access the testserver.

UpdateClntLog

[root_at_eiger]# more UpdateClntLog

Date: Mon 01/22/2001

13:43:56 Update Client pid = 2483 started at Mon Jan 22 13:43:56 2001

13:43:56 Updated db/files

13:43:56 Updated db/auth2.pw

13:43:56 Fetch failed for 'db/auth2.tk.BAK' with No such file or directory

13:43:56 Notifying server eiger.murkworks.com of database updates

13:44:26 Fetch failed for 'db/auth2.tk.BAK' with No such file or directory

13:44:56 Fetch failed for 'db/auth2.tk.BAK' with No such file or directory

13:45:26 Fetch failed for 'db/auth2.tk.BAK' with No such file or directory

---

[root_at_eiger]# more !$
more UpdateSrvLog

Date: Mon 01/22/2001

09:27:12 Update Server working directory /vice
09:27:12 Starting Update Worker 0
09:27:12 Starting Update Worker 1
09:27:12 Update Server started Mon Jan 22 09:27:12 2001

09:27:12 Connection from 128.153.43.27:1062.

---

[root_at_eiger]# more AuthLog 
Starting  Auth Server......

Date: Mon 01/22/2001

09:26:52 Reallocing from 100 to 1000
09:26:52 Server successfully started

09:30:44 In PWGetKeys()
09:30:44        vid = 500
09:30:44        vid = 500
09:30:44 AuthNewConn(0x1cbc42aa, 0, 66, 2, 500)
13:28:06 In PWGetKeys()
13:28:06        vid = -1
13:28:06 Authentication failed for "root" from 127.0.0.1
13:28:13 In PWGetKeys()
13:28:13        vid = 500
13:28:13        vid = 500
13:28:13 AuthNewConn(0x12a0a6f0, 0, 66, 2, 500)
13:29:03 In PWGetKeys()
13:29:03        vid = 500
13:29:03        vid = 500

---

SrvLog

(something looks fishy here)

09:29:33 Vice file system salvager, version 3.0.
09:29:33 SanityCheckFreeLists: Checking RVM Vnode Free lists.
09:29:33 DestroyBadVolumes: Checking for destroyed volumes.
09:29:33 Salvaging file system partition /vicepa
09:29:33 Force salvage of all volumes on this partition
09:29:33 Scanning inodes in directory /vicepa...
09:29:33 SFS: There are some volumes without any inodes in them
09:29:33 SalvageFileSys:  unclaimed volume header file or no Inodes in volume 1000001
09:29:33 SalvageFileSys: Therefore only resetting inUse flag
09:29:33 SalvageFileSys completed on /vicepa
09:29:33 VAttachVolumeById: vol 1000001 (root.0) attached and online
09:29:33 Attached 1 volumes; 0 volumes not attached
lqman: Creating LockQueue Manager.....LockQueue Manager starting .....
09:29:33 LockQueue Manager just did a rvmlib_set_thread_data()

done
09:29:33 CallBackCheckLWP just did a rvmlib_set_thread_data()




Brad Clements,                bkc_at_murkworks.com   (315)268-1000
http://www.murkworks.com                          (315)268-9812 Fax
netmeeting: ils://ils.murkworks.com               AOL-IM: BKClements
Received on 2001-01-22 14:12:46