PAM plugin crashes Percona Server 5.6.14

Bug #1420172 reported by Nilnandan Joshi
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Incomplete
Undecided
Sergei Glushchenko
5.5
Incomplete
Undecided
Sergei Glushchenko
5.6
Incomplete
Undecided
Sergei Glushchenko

Bug Description

04:19:46 UTC - mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=268435456
read_buffer_size=262144
max_used_connections=416
max_threads=2502
thread_count=342
connection_count=342
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2219866 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x56babbf0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7f362ab2cd48 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x8dee25]
/usr/sbin/mysqld(handle_fatal_signal+0x4c4)[0x6659e4]
/lib64/libpthread.so.0[0x3b9de0f710]
/opt/quest/lib64/libvas.so.4(vassym__hc_rijndaelEncrypt+0x43c)[0x7f3629b2929a]
/opt/quest/lib64/libvas.so.4(vassym_hc_AES_encrypt+0x32)[0x7f3629b084e8]
/opt/quest/lib64/libvas.so.4(+0x130efc)[0x7f3629b25efc]
/opt/quest/lib64/libvas.so.4(+0x131168)[0x7f3629b26168]
/opt/quest/lib64/libvas.so.4(+0x1315e4)[0x7f3629b265e4]
/opt/quest/lib64/libvas.so.4(+0x13170a)[0x7f3629b2670a]
/opt/quest/lib64/libvas.so.4(+0x131acf)[0x7f3629b26acf]
/opt/quest/lib64/libvas.so.4(vassym_hc_RAND_bytes+0x31)[0x7f3629b26bfa]
/opt/quest/lib64/libvas.so.4(vassym_krb5_generate_random_block+0x56)[0x7f3629b4942b]
/opt/quest/lib64/libvas.so.4(+0x1676f5)[0x7f3629b5c6f5]
/opt/quest/lib64/libvas.so.4(vassym_krb5_get_init_creds+0xf8)[0x7f3629b5d0dd]
/opt/quest/lib64/libvas.so.4(vassym_krb5_get_init_creds_password+0x2f0)[0x7f3629b5d597]
/opt/quest/lib64/libvas.so.4(+0x1c9097)[0x7f3629bbe097]
/opt/quest/lib64/libvas.so.4(libvas_ticket_get_initial_using_password+0x53)[0x7f3629bbe644]
/opt/quest/lib64/libvas.so.4(vas_id_establish_cred_password+0x278)[0x7f3629b9a3f5]
/lib64/security/pam_vas3.so(+0x1be0d)[0x7f362a06de0d]
/lib64/security/pam_vas3.so(vaslogon_logon+0x43c)[0x7f362a06fd41]
/lib64/security/pam_vas3.so(+0xf6b2)[0x7f362a0616b2]
/lib64/security/pam_vas3.so(pam_vas_am_do_auth+0xde)[0x7f362a063dae]
/lib64/security/pam_vas3.so(pam_sm_authenticate+0xed4)[0x7f362a05ef4a]
/lib64/libpam.so.0[0x3ba1a02cee]
/lib64/libpam.so.0(pam_authenticate+0x40)[0x3ba1a02600]
/usr/lib64/mysql/plugin/auth_pam.so(authenticate_user_with_pam_server+0xed)[0x7f437aab234d]
/usr/sbin/mysqld[0x676f58]
/usr/sbin/mysqld(_Z16acl_authenticateP3THDj+0xe20)[0x682f50]
/usr/sbin/mysqld[0x6b7002]
/usr/sbin/mysqld(_Z16login_connectionP3THD+0x4d)[0x6b721d]
/usr/sbin/mysqld(_Z22thd_prepare_connectionP3THD+0x24)[0x6b7414]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x13f)[0x6b87cf]
/usr/sbin/mysqld(handle_one_connection+0x47)[0x6b88d7]
/usr/sbin/mysqld(pfs_spawn_thread+0x12a)[0x91e4ea]
/lib64/libpthread.so.0[0x3b9de079d1]
/lib64/libc.so.6(clone+0x6d)[0x3b9d6e8b6d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0): is an invalid pointer
Connection ID (thread ID): 520217
Status: NOT_KILLED

You may download the Percona Server operations manual by visiting
http://www.percona.com/software/percona-server/. You may find information
in the manual which will help you identify the cause of the crash.
150210 04:19:46 mysqld_safe Number of processes running now: 0
150210 04:19:46 mysqld_safe mysqld restarted
2015-02-10 04:19:47 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2015-02-10 04:19:47 26058 [Warning] No argument was provided to --log-bin, and --log-bin-index was not used; so replication may break when this MySQL server acts as a master and has his hostname changed!! Please use '--log-bin=qlxdmsql001-bin' to avoid this problem.
2015-02-10 04:19:47 26058 [Warning] Using unique option prefix innodb_read_io_thread instead of innodb-read-io-threads is deprecated and will be removed in a future release. Please use the full name instead.
2015-02-10 04:19:47 26058 [Warning] Using unique option prefix innodb_write_io_thread instead of innodb-write-io-threads is deprecated and will be removed in a future release. Please use the full name instead.
2015-02-10 04:19:47 26058 [Note] Plugin 'FEDERATED' is disabled.
2015-02-10 04:19:47 7f088f2f77e0 InnoDB: Warning: Using innodb_additional_mem_pool_size is DEPRECATED. This option may be removed in future releases, together with the option innodb_use_sys_malloc and with the InnoDB's internal memory allocator.
2015-02-10 04:19:47 26058 [Note] InnoDB: The InnoDB memory heap is disabled
2015-02-10 04:19:47 26058 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-02-10 04:19:47 26058 [Note] InnoDB: Compressed tables use zlib 1.2.3
2015-02-10 04:19:47 26058 [Note] InnoDB: Using Linux native AIO
2015-02-10 04:19:47 26058 [Note] InnoDB: Using CPU crc32 instructions
2015-02-10 04:19:47 26058 [Note] InnoDB: Initializing buffer pool, size = 50.0G
2015-02-10 04:19:49 26058 [Note] InnoDB: Completed initialization of buffer pool
2015-02-10 04:19:49 26058 [Note] InnoDB: Highest supported file format is Barracuda.
2015-02-10 04:19:49 26058 [Note] InnoDB: Log scan progressed past the checkpoint lsn 338894835830
2015-02-10 04:19:49 26058 [Note] InnoDB: Database was not shutdown normally!
2015-02-10 04:19:49 26058 [Note] InnoDB: Starting crash recovery.
2015-02-10 04:19:49 26058 [Note] InnoDB: Reading tablespace information from the .ibd files...
2015-02-10 04:19:49 26058 [Note] InnoDB: Restoring possible half-written data pages
2015-02-10 04:19:49 26058 [Note] InnoDB: from the doublewrite buffer...
InnoDB: Doing recovery: scanned up to log sequence number 338900078592
InnoDB: Doing recovery: scanned up to log sequence number 338905321472
InnoDB: Doing recovery: scanned up to log sequence number 338910564352
InnoDB: Doing recovery: scanned up to log sequence number 338915807232
InnoDB: Doing recovery: scanned up to log sequence number 338921050112
InnoDB: Doing recovery: scanned up to log sequence number 338926292992
InnoDB: Doing recovery: scanned up to log sequence number 338931535872
InnoDB: Doing recovery: scanned up to log sequence number 338936778752
InnoDB: Doing recovery: scanned up to log sequence number 338942021632
InnoDB: Doing recovery: scanned up to log sequence number 338947264512
InnoDB: Doing recovery: scanned up to log sequence number 338952507392
InnoDB: Doing recovery: scanned up to log sequence number 338957750272
InnoDB: Doing recovery: scanned up to log sequence number 338962993152
InnoDB: Doing recovery: scanned up to log sequence number 338968236032
InnoDB: Doing recovery: scanned up to log sequence number 338973478912
InnoDB: Doing recovery: scanned up to log sequence number 338978721792
InnoDB: Doing recovery: scanned up to log sequence number 338983964672
InnoDB: Doing recovery: scanned up to log sequence number 338989207552
InnoDB: Doing recovery: scanned up to log sequence number 338994450432
InnoDB: Doing recovery: scanned up to log sequence number 338999693312
InnoDB: Doing recovery: scanned up to log sequence number 339004936192
InnoDB: Doing recovery: scanned up to log sequence number 339010179072
InnoDB: Doing recovery: scanned up to log sequence number 339015421952
InnoDB: Doing recovery: scanned up to log sequence number 339020664832
InnoDB: Doing recovery: scanned up to log sequence number 339025907712
InnoDB: Doing recovery: scanned up to log sequence number 339031150592
InnoDB: Doing recovery: scanned up to log sequence number 339036393472
InnoDB: Doing recovery: scanned up to log sequence number 339041636352
InnoDB: Doing recovery: scanned up to log sequence number 339046879232
InnoDB: Doing recovery: scanned up to log sequence number 339052122112
InnoDB: Doing recovery: scanned up to log sequence number 339057364992
InnoDB: Doing recovery: scanned up to log sequence number 339062607872
InnoDB: Doing recovery: scanned up to log sequence number 339067850752
InnoDB: Doing recovery: scanned up to log sequence number 339073093632
InnoDB: Doing recovery: scanned up to log sequence number 339073196044
InnoDB: Transaction 7847805201 was in the XA prepared state.
InnoDB: 1 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 0 row operations to undo
InnoDB: Trx id counter is 7847805696
2015-02-10 04:19:54 26058 [Note] InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Last MySQL binlog file position 0 14372466, file name qlxdmsql001-bin.001604
2015-02-10 04:20:10 26058 [Note] InnoDB: 128 rollback segment(s) are active.
InnoDB: Starting in background the rollback of uncommitted transactions
2015-02-10 04:20:10 7efad6aa3700 InnoDB: Rollback of non-prepared transactions completed
2015-02-10 04:20:22 26058 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.14-rel62.0 started; log sequence number 339073196044
2015-02-10 04:20:22 26058 [Note] Recovering after a crash using qlxdmsql001-bin
2015-02-10 04:20:22 26058 [Note] Starting crash recovery...
2015-02-10 04:20:22 7f088f2f77e0 InnoDB: Starting recovery for XA transactions...
2015-02-10 04:20:22 7f088f2f77e0 InnoDB: Transaction 7847805201 in prepared state after recovery
2015-02-10 04:20:22 7f088f2f77e0 InnoDB: Transaction contains changes to 1 rows
2015-02-10 04:20:22 7f088f2f77e0 InnoDB: 1 transactions in prepared state after recovery
2015-02-10 04:20:22 26058 [Note] Found 1 prepared transaction(s) in InnoDB
2015-02-10 04:20:22 26058 [Note] Crash recovery finished.
2015-02-10 04:20:22 26058 [Note] RSA private key file not found: /u01/mysql_data//private_key.pem. Some authentication plugins will not work.
2015-02-10 04:20:22 26058 [Note] RSA public key file not found: /u01/mysql_data//public_key.pem. Some authentication plugins will not work.
2015-02-10 04:20:22 26058 [Note] Server hostname (bind-address): '*'; port: 3306
2015-02-10 04:20:22 26058 [Note] IPv6 is available.
2015-02-10 04:20:22 26058 [Note] - '::' resolves to '::';
2015-02-10 04:20:22 26058 [Note] Server socket created on IP: '::'.
2015-02-10 04:20:22 26058 [Note] Event Scheduler: Loaded 1 event
2015-02-10 04:20:22 26058 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.14-56-log' socket: '/u01/mysql_data/mysql.sock' port: 3306 Percona Server (GPL), Release rel62.0, Revision 483

Tags: pam i50815
tags: added: i50815
Revision history for this message
Nilnandan Joshi (nilnandan-joshi) wrote :

Is anyone able to reproduce this error with recent 5.5 and 5.6 versions?

tags: added: pam
Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-3260

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.