Attachment 713777 Details for Bug 1021307

Perf output as of 11-02-2017

2017-02-11_perfout.txt (text/plain), 17.06 KB, created by Siegbert Sadowski on 2017-02-11 20:13:22 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Siegbert Sadowski

Created: 2017-02-11 20:13:22 UTC

Size: 17.06 KB

patch

obsolete

>--- screenshot of perf trace -e --duration=1000 -e fdatasync,fsync,msync,sync,sync_file_range,syncfs --pid=$(pgrep systemd-journal) > perfout.txt ---
>
>serv2:~ # perf trace -e --duration=1000 -e fdatasync,fsync,msync,sync,sync_file_range,syncfs --pid=$(pgrep systemd-journal) > perfout.txt
>     8.445 ( 8.445 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>    20.180 (11.688 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>132795.992 ( 7.531 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>432980.905 ( 0.007 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>432987.606 ( 6.683 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>595005.396 (13.552 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>895210.254 ( 0.017 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>895218.010 ( 7.705 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>979506.244 ( 7.598 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>1279692.440 ( 0.019 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>1279700.100 ( 7.613 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>1500525.203 ( 6.061 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>1800668.469 ( 0.018 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>1800675.845 ( 7.328 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>2179558.788 ( 7.604 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>2479637.844 ( 0.009 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>2479649.760 (11.892 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>2592241.016 ( 7.556 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>2892369.589 ( 0.009 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>2892376.936 ( 7.320 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>3299589.741 ( 5.960 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>3599588.806 ( 0.020 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>3599596.614 ( 7.756 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>3619907.526 ( 7.499 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>3920074.759 ( 0.020 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>3920082.337 ( 7.526 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>3979674.038 (11.707 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>4279808.831 ( 0.010 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>4279821.507 (12.647 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>4392424.673 (13.366 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>4692540.501 ( 0.010 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>4692547.745 ( 7.216 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>5098658.648 (10.233 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>5398758.229 ( 0.015 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>5398765.998 ( 7.727 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>5779867.379 ( 7.621 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>6079977.443 ( 0.020 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>6079985.065 ( 7.564 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>6191545.582 ( 8.118 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>6491708.848 ( 0.008 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>6491716.511 ( 7.638 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>6898877.293 ( 6.863 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>7198927.093 ( 0.020 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>7198934.690 ( 7.542 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>7234625.346 ( 7.265 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>7534662.082 ( 0.019 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>7534669.820 ( 7.687 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>7583628.210 (13.504 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>7883646.414 ( 0.009 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>7883653.973 ( 7.535 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>8188640.956 ( 8.157 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>8188646.829 ( 5.857 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>8783767.569 ( 7.655 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>9083842.925 ( 0.021 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>9083850.714 ( 7.731 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>9383840.644 ( 7.631 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>9684066.104 ( 0.021 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>9684079.440 (13.279 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>9791775.972 (13.375 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>10091797.838 ( 0.009 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>10091805.411 ( 7.545 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>10288243.539 ( 8.056 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>10588283.737 ( 8.082 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>10588289.428 ( 5.673 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>10691808.382 (11.780 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>10992015.547 ( 7.995 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>10992021.342 ( 5.777 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>11183879.791 ( 7.722 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>11483985.573 ( 0.020 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>11483993.211 ( 7.581 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>11591870.963 ( 7.479 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>11891967.272 ( 0.010 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>11891974.926 ( 7.628 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>12186609.750 (14.053 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>12486698.443 ( 7.734 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>12486704.294 ( 5.834 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>12491908.423 (13.335 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>12791927.112 ( 0.013 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>12791934.622 ( 7.477 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>12983962.877 ( 7.621 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>13284162.849 ( 7.598 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>13284168.574 ( 5.697 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>13391941.450 ( 7.392 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>13692136.912 ( 0.018 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>13692144.515 ( 7.554 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>14174795.042 ( 7.532 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>14474851.914 ( 0.020 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>14474859.753 ( 7.788 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>14784163.296 ( 7.470 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>15084324.671 ( 0.018 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>15084332.560 ( 7.844 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>15192104.010 ( 7.506 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>15492306.501 ( 0.020 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>15492314.404 ( 7.848 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>15899145.139 ( 7.625 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>16199274.960 ( 0.012 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>16199282.510 ( 7.513 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>16584306.914 ( 7.727 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>16884494.430 ( 0.020 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>16884502.179 ( 7.696 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>16991217.848 (12.098 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>17291226.292 ( 0.009 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>17291233.823 ( 7.501 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>17784398.258 ( 7.581 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>18084441.089 ( 0.021 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>18084453.259 (12.114 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>18384414.059 ( 7.534 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>18684414.408 ( 0.020 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>18684422.080 ( 7.618 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>18791309.672 ( 7.416 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>19091396.304 ( 0.020 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>19091404.033 ( 7.672 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>19584543.545 ( 7.538 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>19884610.958 ( 0.009 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>19884618.590 ( 7.610 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>20184615.640 ( 7.664 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>20484834.349 ( 0.020 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>20484842.022 ( 7.620 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>20591439.280 ( 7.525 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>20891566.316 ( 0.021 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>20891574.176 ( 7.799 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>21374510.705 (11.960 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>21978396.110 (303864.579 ms): fsync(fd: 20</var/log/journal/565b8fb65ab16a395a2a210a586a86d8/system.journal>) = 0
>serv2:~ # ---
>If '---' is not a typo you can use command-not-found to lookup the package that contains it, like this:
>    cnf ---
>serv2:~ # ---
>If '---' is not a typo you can use command-not-found to lookup the package that contains it, like this:
>    cnf ---
>serv2:~ # -----
>If '-----' is not a typo you can use command-not-found to lookup the package that contains it, like this:
>    cnf -----
>serv2:~ # 
>
>------------- screenshot of journalctl -ef at point of crash ---------------
>Feb 11 19:15:27 serv2 ctl_mboxlist[705]: DBERROR: reading /var/lib/imap/db/skipstamp, assuming the worst: No such file or directory
>Feb 11 19:15:27 serv2 ctl_mboxlist[705]: skiplist: checkpointed /var/lib/imap/mailboxes.db (0 records, 144 bytes) in 0 seconds
>Feb 11 19:15:27 serv2 ctl_mboxlist[705]: skiplist: checkpointed /var/lib/imap/annotations.db (0 records, 144 bytes) in 0 seconds
>Feb 11 19:15:27 serv2 su[704]: pam_unix(su-l:session): session closed for user cyrus
>Feb 11 19:15:27 serv2 run-crons[747]: suse.de-cyrus-imapd: OK
>Feb 11 19:15:27 serv2 dbus[878]: [system] Activating service name='org.opensuse.Snapper' (using servicehelper)
>Feb 11 19:15:27 serv2 dbus[878]: [system] Successfully activated service 'org.opensuse.Snapper'
>Feb 11 19:23:08 serv2 systemd-journald[17126]: System journal (/var/log/journal/) is currently using 1.0G.
>                                               Maximum allowed usage is set to 4.0G.
>                                               Leaving at least 4.0G free (of currently available 31.8G of space).
>                                               Enforced usage limit is thus 4.0G, of which 2.9G are still available.
>Feb 11 19:23:08 serv2 systemd-journald[17126]: Journal started
>Feb 11 19:20:55 serv2 systemd[1]: systemd-journald.service: Watchdog timeout (limit 3min)!
>Feb 11 19:23:08 serv2 systemd[1]: Starting Flush Journal to Persistent Storage...
>Feb 11 19:23:08 serv2 systemd[1]: Started Flush Journal to Persistent Storage.
>Feb 11 19:23:08 serv2 systemd-coredump[17121]: Detected coredump of the journal daemon itself, diverted to /var/lib/systemd/coredump/core.systemd-journal.0.6ead75cd6a47443ba7842a2e61c6ef9e.502.1486837388000000.xz.
>Feb 11 19:23:14 serv2 clamd[2291]: SelfCheck: Database status OK.
>Feb 11 19:30:01 serv2 cron[22799]: pam_unix(crond:session): session opened for user root by (uid=0)
>Feb 11 19:30:01 serv2 systemd[1]: Started Session 28 of user root.
>Feb 11 19:30:01 serv2 CRON[22799]: pam_unix(crond:session): session closed for user root
>Feb 11 19:33:15 serv2 clamd[2291]: SelfCheck: Database status OK.
>Feb 11 19:38:07 serv2 systemd-journald[11603]: System journal (/var/log/journal/) is currently using 1.0G.
>                                               Maximum allowed usage is set to 4.0G.
>                                               Leaving at least 4.0G free (of currently available 31.8G of space).
>                                               Enforced usage limit is thus 4.0G, of which 2.9G are still available.
>Feb 11 19:38:07 serv2 systemd-journald[11603]: Journal started
>Feb 11 19:37:15 serv2 systemd[1]: systemd-journald.service: Watchdog timeout (limit 3min)!
>Feb 11 19:38:07 serv2 systemd[1]: Starting Flush Journal to Persistent Storage...
>Feb 11 19:38:07 serv2 systemd[1]: Started Flush Journal to Persistent Storage.
>Feb 11 19:38:07 serv2 systemd-coredump[11584]: Detected coredump of the journal daemon itself, diverted to /var/lib/systemd/coredump/core.systemd-journal.0.6ead75cd6a47443ba7842a2e61c6ef9e.17126.1486838287000000.xz.
>Feb 11 19:43:15 serv2 clamd[2291]: SelfCheck: Database status OK.
>Feb 11 19:44:12 serv2 smartd[886]: Device: /dev/sdb [SAT], SMART Usage Attribute: 194 Temperature_Celsius changed from 113 to 112

Actions: View

Attachments on bug 1021307: 711149 | 711994 | 711995 | 713752 | 713777 | 715475 | 715481 | 715482 | 715483 | 715500 | 719297 | 719368