Back to the future!

Hi,

dmesg:

[    0.000000] ... MAX_LOCKDEP_CHAINS:      32768
[    0.000000] ... CHAINHASH_SIZE:          16384
[    0.000000]  memory used by lock dependency info: 5855 kB
[    0.000000]  per task-struct memory footprint: 1920 bytes
[    0.000000] hpet clockevent registered
[    0.000000] Fast TSC calibration using PIT
[    0.003333] Detected 2261.025 MHz processor.
[    0.000012] Calibrating delay loop (skipped), value calculated using timer frequency.. 4523.46 BogoMIPS (lpj=7536750)
[    0.000176] pid_max: default: 32768 minimum: 301
[    0.000308] Security Framework initialized
[    0.000413] Mount-cache hash table entries: 256
[    0.001246] Initializing cgroup subsys ns
[    0.001328] Initializing cgroup subsys cpuacct
[    0.001413] Initializing cgroup subsys devices
[    0.001493] Initializing cgroup subsys blkio


Actually, the one and only cool thing about Acer Aspire 5741G. Yeah...

I/O load

Hi,

Finding the source of I/O load:

echo 1 > /proc/sys/vm/block_dump
dmesg /*add grep | sort | head | whatever you like*/

[23303.008133] jbd2/sda7-8(3588): WRITE block 73544 on sda7
[23303.009090] jbd2/sda5-8(1315): WRITE block 2506872 on sda5
[23303.009169] jbd2/sda5-8(1315): WRITE block 8740776 on sda5
[23303.009189] jbd2/sda5-8(1315): WRITE block 8740784 on sda5
[23303.009204] jbd2/sda5-8(1315): WRITE block 8740792 on sda5
[23303.012135] syslog-ng(3725): READ block 1572968 on sda5
[23303.012168] syslog-ng(3725): READ block 1573000 on sda5
[23303.012201] syslog-ng(3725): READ block 1573064 on sda5
[23303.012221] syslog-ng(3725): READ block 1573080 on sda5
[23303.012243] syslog-ng(3725): READ block 1573104 on sda5
[23303.012261] syslog-ng(3725): READ block 1573176 on sda5
[23303.068168] syslog-ng(3725): dirtied inode 14390 (everything.log) on sda5
[23303.068194] syslog-ng(3725): dirtied inode 14390 (everything.log) on sda5
[23303.068205] syslog-ng(3725): dirtied inode 14390 (everything.log) on sda5
[23303.068525] syslog-ng(3725): dirtied inode 14386 (kernel.log) on sda5
[23303.068543] syslog-ng(3725): dirtied inode 14386 (kernel.log) on sda5
[23303.068552] syslog-ng(3725): dirtied inode 14386 (kernel.log) on sda5
[23303.072523] jbd2/sda5-8(1315): WRITE block 8740800 on sda5
[23307.374341] bash(30701): READ block 417840 on sda5
[23307.408615] bash(30701): dirtied inode 7275 (dmesg) on sda5
[23309.008101] jbd2/sda5-8(1315): WRITE block 2711320 on sda5
[23309.008156] jbd2/sda5-8(1315): WRITE block 2806184 on sda5
[23309.008229] jbd2/sda5-8(1315): WRITE block 8740808 on sda5
[23309.008248] jbd2/sda5-8(1315): WRITE block 8740816 on sda5
[23309.008262] jbd2/sda5-8(1315): WRITE block 8740824 on sda5
[23309.020531] jbd2/sda5-8(1315): WRITE block 8740832 on sda5
[23312.836095] flush-8:0(1348): WRITE block 19660808 on sda7
[23312.836137] flush-8:0(1348): WRITE block 19660832 on sda7
[23312.836159] flush-8:0(1348): WRITE block 19661496 on sda7
[23312.836178] flush-8:0(1348): WRITE block 19968464 on sda7
[23312.836288] flush-8:0(1348): WRITE block 0 on sda7
[23312.836307] flush-8:0(1348): WRITE block 8 on sda7
[23315.008123] jbd2/sda5-8(1315): WRITE block 8740840 on sda5
[23315.008246] jbd2/sda5-8(1315): WRITE block 8740848 on sda5
[23315.018987] jbd2/sda5-8(1315): WRITE block 8740856 on sda5
[..]
[23384.161854] firefox(30716): WRITE block 4107056 on sda7
[23384.161860] firefox(30716): WRITE block 4107064 on sda7
[23384.161867] firefox(30716): WRITE block 4107072 on sda7
[23384.161873] firefox(30716): WRITE block 4107080 on sda7
[23384.161880] firefox(30716): WRITE block 4107088 on sda7
[23384.161886] firefox(30716): WRITE block 4107096 on sda7
[23384.161952] firefox(30716): WRITE block 4107104 on sda7
[23384.161960] firefox(30716): WRITE block 4107112 on sda7
[23384.161967] firefox(30716): WRITE block 4107120 on sda7
[23384.161974] firefox(30716): WRITE block 4107128 on sda7
[23384.161980] firefox(30716): WRITE block 4107136 on sda7
[23384.161987] firefox(30716): WRITE block 4107144 on sda7
[23384.161993] firefox(30716): WRITE block 4107152 on sda7
[23384.161999] firefox(30716): WRITE block 4107160 on sda7
[23384.162006] firefox(30716): WRITE block 4107168 on sda7
[23384.162013] firefox(30716): WRITE block 4107176 on sda7
[23384.162019] firefox(30716): WRITE block 4107184 on sda7
[23384.162026] firefox(30716): WRITE block 4107192 on sda7
[23384.162033] firefox(30716): WRITE block 4107200 on sda7
[23384.162039] firefox(30716): WRITE block 4107208 on sda7
[23384.162047] firefox(30716): WRITE block 4107216 on sda7

Surely You're Joking, Mr. Feynman!

Hi,

Currently I'm reading "Surely You're Joking, Mr. Feynman! (Adventures of a Curious Character)".
And this book rocks. Really. Unique mix of enormous amount of knowledge, curiosity, humor... And
everything else you wouldn't expect from a Nobel-winner physicist.

And yeah, this is recommended reading.


The next one I'd like to read is
"Reminiscences of Los Alamos 1943-1945 (Studies in the History of Modern Science)".

Ever seen a grown man naked?

Greetings everyone,

I've published a simple code which, however, targets some 'not so easy'
problems in vfs/reiserfs.

Like deadlock:

[  573.405720]
[  573.405722] =======================================================
[  573.405728] [ INFO: possible circular locking dependency detected ]
[  573.405732] 2.6.35-rc3-dbg-git6-00502-g94feaba-dirty #65
[  573.405735] -------------------------------------------------------
[  573.405739] a.out/7287 is trying to acquire lock:
[  573.405742]  (&sb->s_type->i_mutex_key#10){+.+.+.}, at: [] reiserfs_file_release+0x11d/0x344
[  573.405758]
[  573.405759] but task is already holding lock:
[  573.405762]  (&mm->mmap_sem){++++++}, at: [] sys_mmap_pgoff+0xa4/0xe7
[  573.405772]
[  573.405773] which lock already depends on the new lock.
[  573.405774]
[  573.405777]
[  573.405778] the existing dependency chain (in reverse order) is:
[  573.405781]
[  573.405782] -> #1 (&mm->mmap_sem){++++++}:
[  573.405789]        [] lock_acquire+0x59/0x70
[  573.405797]        [] might_fault+0x53/0x70
[  573.405803]        [] copy_to_user+0x30/0x48
[  573.405809]        [] filldir64+0x95/0xc9
[  573.405815]        [] reiserfs_readdir_dentry+0x35d/0x4d9
[  573.405821]        [] reiserfs_readdir+0x12/0x17
[  573.405827]        [] vfs_readdir+0x6d/0x92
[  573.405831]        [] sys_getdents64+0x63/0xa2
[  573.405836]        [] sysenter_do_call+0x12/0x32
[  573.405843]
[  573.405843] -> #0 (&sb->s_type->i_mutex_key#10){+.+.+.}:
[  573.405851]        [] __lock_acquire+0x96d/0xbe1
[  573.405857]        [] lock_acquire+0x59/0x70
[  573.405862]        [] __mutex_lock_common+0x39/0x36b
[  573.405869]        [] mutex_lock_nested+0x12/0x15
[  573.405874]        [] reiserfs_file_release+0x11d/0x344
[  573.405880]        [] fput+0xe0/0x16a
[  573.405886]        [] remove_vma+0x28/0x47
[  573.405892]        [] do_munmap+0x1e8/0x200
[  573.405897]        [] mmap_region+0x6b/0x372
[  573.405902]        [] do_mmap_pgoff+0x23c/0x282
[  573.405908]        [] sys_mmap_pgoff+0xbd/0xe7
[  573.405913]        [] sysenter_do_call+0x12/0x32
[  573.405919]
[  573.405920] other info that might help us debug this:
[  573.405921]
[  573.405925] 1 lock held by a.out/7287:
[  573.405928]  #0:  (&mm->mmap_sem){++++++}, at: [] sys_mmap_pgoff+0xa4/0xe7
[  573.405937]
[  573.405938] stack backtrace:
[  573.405942] Pid: 7287, comm: a.out Not tainted 2.6.35-rc3-dbg-git6-00502-g94feaba-dirty #65
[  573.405946] Call Trace:
[  573.405951]  [] ? printk+0xf/0x11
[  573.405957]  [] print_circular_bug+0x8a/0x96
[  573.405962]  [] __lock_acquire+0x96d/0xbe1
[  573.405969]  [] ? mark_lock+0x26/0x1b3
[  573.405975]  [] lock_acquire+0x59/0x70
[  573.405980]  [] ? reiserfs_file_release+0x11d/0x344
[  573.405986]  [] __mutex_lock_common+0x39/0x36b
[  573.405991]  [] ? reiserfs_file_release+0x11d/0x344
[  573.405997]  [] mutex_lock_nested+0x12/0x15
[  573.406003]  [] ? reiserfs_file_release+0x11d/0x344
[  573.406008]  [] reiserfs_file_release+0x11d/0x344
[  573.406014]  [] ? fput+0x90/0x16a
[  573.406019]  [] fput+0xe0/0x16a
[  573.406024]  [] remove_vma+0x28/0x47
[  573.406030]  [] ? arch_unmap_area_topdown+0x0/0x18
[  573.406035]  [] do_munmap+0x1e8/0x200
[  573.406040]  [] mmap_region+0x6b/0x372
[  573.406046]  [] do_mmap_pgoff+0x23c/0x282
[  573.406052]  [] sys_mmap_pgoff+0xbd/0xe7
[  573.406058]  [] sysenter_do_call+0x12/0x32


Error causing RO remount:
[  202.300464] REISERFS error (device sda9): vs-2100 add_save_link:
search_by_key ([-1 7812832 0x1 IND]) returned 1
[  202.300473] REISERFS (device sda9): Remounting filesystem read-only
[  202.301603] ------------[ cut here ]------------
[  202.301615] WARNING: at fs/reiserfs/journal.c:3436
journal_end+0x5b/0xaf()
[  202.301689] Pid: 5055, comm: a.out Not tainted
2.6.35-rc3-dbg-git6-00502-g94feaba-dirty #65
[  202.301693] Call Trace:
[  202.301701]  [] warn_slowpath_common+0x65/0x7a
[  202.301707]  [] ? journal_end+0x5b/0xaf
[  202.301712]  [] warn_slowpath_null+0xf/0x13
[  202.301718]  [] journal_end+0x5b/0xaf
[  202.301725]  [] reiserfs_truncate_file+0x19f/0x233
[  202.301733]  [] reiserfs_vfs_truncate_file+0xd/0xf
[  202.301738]  [] vmtruncate+0x23/0x29
[  202.301745]  [] inode_setattr+0x47/0x68
[  202.301751]  [] reiserfs_setattr+0x242/0x297
[  202.301758]  [] ? down_write+0x22/0x2a
[  202.301764]  [] notify_change+0x15c/0x26b
[  202.301770]  [] do_truncate+0x64/0x7d
[  202.301776]  [] ? _raw_spin_unlock+0x33/0x3f
[  202.301783]  [] do_last+0x450/0x459
[  202.301789]  [] do_filp_open+0x1c0/0x41a
[  202.301798]  [] ? get_parent_ip+0xb/0x31
[  202.301804]  [] ? sub_preempt_count+0x7c/0x89
[  202.301810]  [] ? alloc_fd+0xb4/0xbf
[  202.301816]  [] do_sys_open+0x48/0xdf
[  202.301821]  [] sys_open+0x1e/0x26
[  202.301827]  [] sysenter_do_call+0x12/0x32
[  202.301833] ---[ end trace c4e3312bdadd2dc5 ]---

And even OOps...

Al Viro wrote:
> OK...  See 22093b8f3d387f77 in vfs-2.6.git for-next (should
> propagate to git.kernel.org shortly).  That ought to deal with
> this crap, assuming I hadn't fucked up somewhere...

YAY!

/*
 * 2010, Sergey Senozhatsky. GPLv2
 *
*/

[..]

int main()
{
    char buf[4096];
    int i = 0;
    /* we don't really care */
    for (; i < 4096; i++)
        buf[i] = (i + 65) % 255;

    for (i = 0; i < 10; i++) {

        int pid = fork();
        if (pid > 0 ) {
            printf("parent...");
        } else if (pid == 0) {
           
            printf("child...\n");
            int fd = open("conftest.mmap", O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE, 0600);
            if (fd > 0) {
                printf("OPEN ok %d\n", fd);
                if (write(fd, buf, 4096) < 0)
                    printf("WRITE error\n");
                else
                    printf("WRITE ok\n");
               
                close(fd);
            } else {
                printf("OPEN error\n");
            }
           
            fd = open("conftest.mmap", O_RDWR|O_LARGEFILE);
            if (fd > 0) {
                printf("OPEN conftest.mmap %d\n", fd);
               
                void *map = mmap((void*)0xb78a8000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, fd, 0);
                if (map == MAP_FAILED) {
                    printf("MMAP failed\n");
                    close(fd);
                    goto out;
                } else {
                    printf("MMAP ok\n");
                }
               
                if (read(fd, buf, 4096) < 0)
                    printf("READ failed\n");
                else
                    printf("READ ok\n");

                close(fd);
                munmap(map, 4096);
            } else {
                printf("Error: can't open conftest.mmap\n");
            }
           
        out:
            fd = open(".", O_RDONLY|O_LARGEFILE);
            if (fd > 0) {
                printf("OPEN . ok %d... closing\n", fd);
                close(fd);
            } else {
                printf("OPEN error\n");
            }
           
            struct stat _stat;
            if (fstatat(AT_FDCWD, "conftest.mmap", &_stat, AT_SYMLINK_NOFOLLOW) < 0)
                printf("FSTATAT error\n");
            else
                printf("FSTATAT ok\n");
           
            if (unlinkat(AT_FDCWD, "conftest.mmap", 0) < 0)
                printf("UNLINKAT error\n");
            else
                printf("UNLINKAT ok\n");

            /*
             * Yep...
             * return 0;
             */
        } else {
            printf("FORK error\n");
        }
    }
   
    return 0;
}