Ticket #613 (closed maintenance: fixed)

Opened 3 years ago

Last modified 3 years ago

Parrot mysql console errors

Reported by: chris Owned by: chris
Priority: minor Milestone: Maintenance
Component: Dev server Keywords:
Cc: jim, ed Estimated Number of Hours: 0.0
Add Hours to Ticket: 0 Billable?: yes
Total Hours: 0

Description

I connected to the wiki:ParrotServer wiki:XenShell to check the bandwidth usage and there was the following output, we should try to track down the cause of this:

parrot login: [41569.058444] hrtimer: interrupt took 59422559 ns
[442920.164115] INFO: task mysqld:3522 blocked for more than 120 seconds.
[442920.164133] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[442920.164142] mysqld        D ffff880003755c40     0  3522    711 0x00000000
[442920.164153]  ffff8800bfa68e20 0000000000000282 ffff8800565fb9e8 ffff8800565fb9e4
[442920.164165]  00000000000157c8 0000000000000000 000000000000f9e0 ffff8800565fbfd8
[442920.164175]  00000000000157c0 00000000000157c0 ffff88000180c6a0 ffff88000180c998
[442920.164185] Call Trace:
[442920.164200]  [<ffffffff8110fb96>] ? sync_buffer+0x0/0x40
[442920.164211]  [<ffffffff8130de82>] ? io_schedule+0x73/0xb7
[442920.164219]  [<ffffffff8110fbd1>] ? sync_buffer+0x3b/0x40
[442920.164228]  [<ffffffff8130f142>] ? _spin_unlock_irqrestore+0xd/0xe
[442920.164237]  [<ffffffff8130e292>] ? __wait_on_bit_lock+0x3f/0x84
[442920.164246]  [<ffffffff8110fb96>] ? sync_buffer+0x0/0x40
[442920.164253]  [<ffffffff8130e342>] ? out_of_line_wait_on_bit_lock+0x6b/0x77
[442920.164262]  [<ffffffff81066360>] ? wake_bit_function+0x0/0x23
[442920.164271]  [<ffffffff8110ffc3>] ? sync_dirty_buffer+0x29/0x93
[442920.164286]  [<ffffffffa001be04>] ? journal_dirty_data+0xd1/0x1b0 [jbd]
[442920.164301]  [<ffffffffa0032f4c>] ? ext3_journal_dirty_data+0xf/0x34 [ext3]
[442920.164312]  [<ffffffffa00313f5>] ? walk_page_buffers+0x65/0x8b [ext3]
[442920.164322]  [<ffffffffa0032f71>] ? journal_dirty_data_fn+0x0/0x13 [ext3]
[442920.164333]  [<ffffffffa0034a93>] ? ext3_ordered_write_end+0x73/0x10f [ext3]
[442920.164343]  [<ffffffff810b648a>] ? generic_file_buffered_write+0x18d/0x278
[442920.164352]  [<ffffffff810b6926>] ? __generic_file_aio_write+0x25f/0x293
[442920.164361]  [<ffffffff810b69b3>] ? generic_file_aio_write+0x59/0x9f
[442920.164369]  [<ffffffff810f0316>] ? do_sync_write+0xce/0x113
[442920.164377]  [<ffffffff81066332>] ? autoremove_wake_function+0x0/0x2e
[442920.164385]  [<ffffffff8130f6fa>] ? error_exit+0x2a/0x60
[442920.164394]  [<ffffffff8101251d>] ? retint_restore_args+0x5/0x6
[442920.164403]  [<ffffffff8102de30>] ? pvclock_clocksource_read+0x3a/0x8b
[442920.164411]  [<ffffffff810f0c68>] ? vfs_write+0xa9/0x102
[442920.164419]  [<ffffffff810f0d7d>] ? sys_write+0x45/0x6e
[442920.164427]  [<ffffffff81011b42>] ? system_call_fastpath+0x16/0x1b
[442920.164435] INFO: task mysqld:21061 blocked for more than 120 seconds.
[442920.164441] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[442920.164448] mysqld        D ffff8800018b0e20     0 21061    711 0x00000000
[442920.164457]  ffff8800018b0e20 0000000000000282 ffffffff8100c426 ffffffff8100e233
[442920.164469]  ffff880003755d10 0000000000000002 000000000000f9e0 ffff8800bdde3fd8
[442920.164480]  00000000000157c0 00000000000157c0 ffff8800bd9462e0 ffff8800bd9465d8
[442920.164492] Call Trace:
[442920.164498]  [<ffffffff8100c426>] ? pfn_to_mfn+0xe/0x22
[442920.164506]  [<ffffffff8100e233>] ? arbitrary_virt_to_machine+0x28/0x73
[442920.164515]  [<ffffffff8110fb96>] ? sync_buffer+0x0/0x40
[442920.164523]  [<ffffffff8106ce4a>] ? timekeeping_get_ns+0xe/0x2e
[442920.164531]  [<ffffffff8110fb96>] ? sync_buffer+0x0/0x40
[442920.164538]  [<ffffffff8130de82>] ? io_schedule+0x73/0xb7
[442920.164545]  [<ffffffff8110fbd1>] ? sync_buffer+0x3b/0x40
[442920.164554]  [<ffffffff8130f142>] ? _spin_unlock_irqrestore+0xd/0xe
[442920.164561]  [<ffffffff8130e292>] ? __wait_on_bit_lock+0x3f/0x84
[442920.164569]  [<ffffffff8110fb96>] ? sync_buffer+0x0/0x40
[442920.164576]  [<ffffffff8130e342>] ? out_of_line_wait_on_bit_lock+0x6b/0x77
[442920.164584]  [<ffffffff81066360>] ? wake_bit_function+0x0/0x23
[442920.164592]  [<ffffffff8110ffc3>] ? sync_dirty_buffer+0x29/0x93
[442920.164600]  [<ffffffffa001be04>] ? journal_dirty_data+0xd1/0x1b0 [jbd]
[442920.164611]  [<ffffffffa0032f4c>] ? ext3_journal_dirty_data+0xf/0x34 [ext3]
[442920.164622]  [<ffffffffa00313f5>] ? walk_page_buffers+0x65/0x8b [ext3]
[442920.164632]  [<ffffffffa0032f71>] ? journal_dirty_data_fn+0x0/0x13 [ext3]
[442920.164643]  [<ffffffffa0034a93>] ? ext3_ordered_write_end+0x73/0x10f [ext3]
[442920.164652]  [<ffffffff810b648a>] ? generic_file_buffered_write+0x18d/0x278
[442920.164661]  [<ffffffff810b6926>] ? __generic_file_aio_write+0x25f/0x293
[442920.164670]  [<ffffffff810b69b3>] ? generic_file_aio_write+0x59/0x9f
[442920.164677]  [<ffffffff810f0316>] ? do_sync_write+0xce/0x113
[442920.164685]  [<ffffffff81066332>] ? autoremove_wake_function+0x0/0x2e
[442920.164693]  [<ffffffff810f0c68>] ? vfs_write+0xa9/0x102
[442920.164700]  [<ffffffff810f0d18>] ? sys_pwrite64+0x57/0x77
[442920.164706]  [<ffffffff81011b42>] ? system_call_fastpath+0x16/0x1b

Change History

comment:1 Changed 3 years ago by chris

  • Status changed from new to closed
  • Resolution set to fixed

I have just checked the Xen console again and there are more messages like this:

[2940960.209948]  [<ffffffff81066360>] ? wake_bit_function+0x0/0x23
[2940960.209962]  [<ffffffffa001c402>] ? jbd2_journal_get_write_access+0x22/0x33 [jbd2]
[2940960.209983]  [<ffffffffa006289e>] ? __ext4_journal_get_write_access+0x4e/0x56 [ext4]
[2940960.209999]  [<ffffffffa0042b8e>] ? ext4_reserve_inode_write+0x37/0x73 [ext4]
[2940960.210028]  [<ffffffffa0042c05>] ? ext4_mark_inode_dirty+0x3b/0x1c4 [ext4]
[2940960.210043]  [<ffffffffa005bdc7>] ? ext4_journal_start_sb+0xd4/0x10e [ext4]
[2940960.210054]  [<ffffffff81290afb>] ? tcp_recvmsg+0x98b/0xa9e
[2940960.210069]  [<ffffffffa0042eb0>] ? ext4_dirty_inode+0x30/0x46 [ext4]
[2940960.210078]  [<ffffffff81109ead>] ? __mark_inode_dirty+0x25/0x14a
[2940960.210086]  [<ffffffff8110138b>] ? file_update_time+0x101/0x130
[2940960.210094]  [<ffffffff810b6835>] ? __generic_file_aio_write+0x16e/0x293
[2940960.210103]  [<ffffffff81252468>] ? sock_aio_read+0xb9/0xc4
[2940960.210110]  [<ffffffff8100cc43>] ? xen_make_pte+0x7b/0x83
[2940960.210117]  [<ffffffff810b69b3>] ? generic_file_aio_write+0x59/0x9f
[2940960.210125]  [<ffffffff810f0316>] ? do_sync_write+0xce/0x113
[2940960.210133]  [<ffffffff81066332>] ? autoremove_wake_function+0x0/0x2e
[2940960.210141]  [<ffffffff810ce24c>] ? handle_mm_fault+0x3b8/0x80f
[2940960.210148]  [<ffffffff810f0c68>] ? vfs_write+0xa9/0x102
[2940960.210155]  [<ffffffff810f0d7d>] ? sys_write+0x45/0x6e
[2940960.210162]  [<ffffffff81011b42>] ? system_call_fastpath+0x16/0x1b
[5273520.284212] INFO: task mysqld:6145 blocked for more than 120 seconds.
[5273520.284231] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[5273520.284240] mysqld        D ffff88008dea1ec0     0  6145  22050 0x00000000
[5273520.284251]  ffff8800bcc69530 0000000000000286 ffffffff8130f142 ffffffff8104b51c
[5273520.284263]  0007ffffffffffff 0000000000000001 000000000000f9e0 ffff88008dea1fd8
[5273520.284273]  00000000000157c0 00000000000157c0 ffff880001939c40 ffff880001939f38
[5273520.284284] Call Trace:
[5273520.284300]  [<ffffffff8130f142>] ? _spin_unlock_irqrestore+0xd/0xe
[5273520.284311]  [<ffffffff8104b51c>] ? try_to_wake_up+0x289/0x29b
[5273520.284323]  [<ffffffff8106633b>] ? autoremove_wake_function+0x9/0x2e
[5273520.284342]  [<ffffffffa00232bf>] ? jbd2_log_wait_commit+0xbf/0x112 [jbd2]
[5273520.284350]  [<ffffffff81066332>] ? autoremove_wake_function+0x0/0x2e
[5273520.284369]  [<ffffffffa003fb41>] ? ext4_sync_file+0x199/0x25c [ext4]
[5273520.284381]  [<ffffffff8110d6e0>] ? vfs_fsync_range+0x73/0x9e
[5273520.284389]  [<ffffffff8110d78a>] ? do_fsync+0x28/0x39
[5273520.284395]  [<ffffffff8110d7b9>] ? sys_fsync+0xb/0x10
[5273520.284403]  [<ffffffff81011b63>] ? sysret_check+0x17/0x5a
[5273520.284411]  [<ffffffff81011b42>] ? system_call_fastpath+0x16/0x1b
[5359920.284150] INFO: task mysqld:29884 blocked for more than 120 seconds.
[5359920.284168] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[5359920.284177] mysqld        D 0000000000000000     0 29884  22050 0x00000000
[5359920.284188]  ffff8800bfa68e20 0000000000000286 0000000000000000 ffffffff8104b51c
[5359920.284199]  0007ffffffffffff 0000000000000001 000000000000f9e0 ffff8800bd765fd8
[5359920.284210]  00000000000157c0 00000000000157c0 ffff88000182d4c0 ffff88000182d7b8
[5359920.284220] Call Trace:
[5359920.284234]  [<ffffffff8104b51c>] ? try_to_wake_up+0x289/0x29b
[5359920.284245]  [<ffffffff8106633b>] ? autoremove_wake_function+0x9/0x2e
[5359920.284264]  [<ffffffffa00232bf>] ? jbd2_log_wait_commit+0xbf/0x112 [jbd2]
[5359920.284275]  [<ffffffff81066332>] ? autoremove_wake_function+0x0/0x2e
[5359920.284296]  [<ffffffffa003fb41>] ? ext4_sync_file+0x199/0x25c [ext4]
[5359920.284306]  [<ffffffff8110d6e0>] ? vfs_fsync_range+0x73/0x9e
[5359920.284315]  [<ffffffff8110d78a>] ? do_fsync+0x28/0x39
[5359920.284322]  [<ffffffff8110d7b9>] ? sys_fsync+0xb/0x10
[5359920.284330]  [<ffffffff81011b63>] ? sysret_check+0x17/0x5a
[5359920.284336]  [<ffffffff81011b42>] ? system_call_fastpath+0x16/0x1b

Looking at /var/log/messages on wiki:ParrotServer this last happened at Mar 25 01:03:22 -- before the fix for the NFS/ZFS server, see ticket:618#comment:5 and I expect that that fix has solved this, so closing.

Note: See TracTickets for help on using tickets.