1 /* $Id: fpm_php_trace.c,v 1.27.2.1 2008/11/15 00:57:24 anight Exp $ */
2 /* (c) 2007,2008 Andrei Nigmatulin */
3
4 #include "fpm_config.h"
5
6 #if HAVE_FPM_TRACE
7
8 #include "php.h"
9 #include "php_main.h"
10
11 #include <stdio.h>
12 #include <stddef.h>
13 #if HAVE_INTTYPES_H
14 # include <inttypes.h>
15 #else
16 # include <stdint.h>
17 #endif
18 #include <unistd.h>
19 #include <sys/time.h>
20 #include <sys/types.h>
21 #include <errno.h>
22
23 #include "fpm_trace.h"
24 #include "fpm_php_trace.h"
25 #include "fpm_children.h"
26 #include "fpm_worker_pool.h"
27 #include "fpm_process_ctl.h"
28 #include "fpm_scoreboard.h"
29
30 #include "zlog.h"
31
32
33 #define valid_ptr(p) ((p) && 0 == ((p) & (sizeof(long) - 1)))
34
35 #if SIZEOF_LONG == 4
36 #define PTR_FMT "08"
37 #elif SIZEOF_LONG == 8
38 #define PTR_FMT "016"
39 #endif
40
41
fpm_php_trace_dump(struct fpm_child_s * child,FILE * slowlog)42 static int fpm_php_trace_dump(struct fpm_child_s *child, FILE *slowlog) /* {{{ */
43 {
44 int callers_limit = child->wp->config->request_slowlog_trace_depth;
45 pid_t pid = child->pid;
46 struct timeval tv;
47 static const int buf_size = 1024;
48 char buf[buf_size];
49 long execute_data;
50 long path_translated;
51 long l;
52
53 gettimeofday(&tv, 0);
54
55 zlog_print_time(&tv, buf, buf_size);
56
57 fprintf(slowlog, "\n%s [pool %s] pid %d\n", buf, child->wp->config->name, (int) pid);
58
59 if (0 > fpm_trace_get_long((long) &SG(request_info).path_translated, &l)) {
60 return -1;
61 }
62
63 path_translated = l;
64
65 if (0 > fpm_trace_get_strz(buf, buf_size, path_translated)) {
66 return -1;
67 }
68
69 fprintf(slowlog, "script_filename = %s\n", buf);
70
71 if (0 > fpm_trace_get_long((long) &EG(current_execute_data), &l)) {
72 return -1;
73 }
74
75 execute_data = l;
76
77 while (execute_data) {
78 long function;
79 long function_name;
80 long file_name;
81 long prev;
82 uint32_t lineno = 0;
83
84 if (0 > fpm_trace_get_long(execute_data + offsetof(zend_execute_data, func), &l)) {
85 return -1;
86 }
87
88 function = l;
89
90 if (valid_ptr(function)) {
91 if (0 > fpm_trace_get_long(function + offsetof(zend_function, common.function_name), &l)) {
92 return -1;
93 }
94
95 function_name = l;
96
97 if (function_name == 0) {
98 uint32_t *call_info = (uint32_t *)&l;
99 if (0 > fpm_trace_get_long(execute_data + offsetof(zend_execute_data, This.u1.type_info), &l)) {
100 return -1;
101 }
102
103 if (ZEND_CALL_KIND_EX((*call_info) >> ZEND_CALL_INFO_SHIFT) == ZEND_CALL_TOP_CODE) {
104 return 0;
105 } else if (ZEND_CALL_KIND_EX(*(call_info) >> ZEND_CALL_INFO_SHIFT) == ZEND_CALL_NESTED_CODE) {
106 memcpy(buf, "[INCLUDE_OR_EVAL]", sizeof("[INCLUDE_OR_EVAL]"));
107 } else {
108 ZEND_ASSERT(0);
109 }
110 } else {
111 if (0 > fpm_trace_get_strz(buf, buf_size, function_name + offsetof(zend_string, val))) {
112 return -1;
113 }
114
115 }
116 } else {
117 memcpy(buf, "???", sizeof("???"));
118 }
119
120 fprintf(slowlog, "[0x%" PTR_FMT "lx] ", execute_data);
121
122 fprintf(slowlog, "%s()", buf);
123
124 *buf = '\0';
125
126 if (0 > fpm_trace_get_long(execute_data + offsetof(zend_execute_data, prev_execute_data), &l)) {
127 return -1;
128 }
129
130 execute_data = prev = l;
131
132 while (prev) {
133 zend_uchar *type;
134
135 if (0 > fpm_trace_get_long(prev + offsetof(zend_execute_data, func), &l)) {
136 return -1;
137 }
138
139 function = l;
140
141 if (!valid_ptr(function)) {
142 break;
143 }
144
145 type = (zend_uchar *)&l;
146 if (0 > fpm_trace_get_long(function + offsetof(zend_function, type), &l)) {
147 return -1;
148 }
149
150 if (ZEND_USER_CODE(*type)) {
151 if (0 > fpm_trace_get_long(function + offsetof(zend_op_array, filename), &l)) {
152 return -1;
153 }
154
155 file_name = l;
156
157 if (0 > fpm_trace_get_strz(buf, buf_size, file_name + offsetof(zend_string, val))) {
158 return -1;
159 }
160
161 if (0 > fpm_trace_get_long(prev + offsetof(zend_execute_data, opline), &l)) {
162 return -1;
163 }
164
165 if (valid_ptr(l)) {
166 long opline = l;
167 uint32_t *lu = (uint32_t *) &l;
168
169 if (0 > fpm_trace_get_long(opline + offsetof(struct _zend_op, lineno), &l)) {
170 return -1;
171 }
172
173 lineno = *lu;
174 }
175 break;
176 }
177
178 if (0 > fpm_trace_get_long(prev + offsetof(zend_execute_data, prev_execute_data), &l)) {
179 return -1;
180 }
181
182 prev = l;
183 }
184
185 fprintf(slowlog, " %s:%u\n", *buf ? buf : "unknown", lineno);
186
187 if (0 == --callers_limit) {
188 break;
189 }
190 }
191
192 return 0;
193 }
194 /* }}} */
195
fpm_php_trace(struct fpm_child_s * child)196 void fpm_php_trace(struct fpm_child_s *child) /* {{{ */
197 {
198 fpm_scoreboard_update(0, 0, 0, 0, 0, 0, 1, FPM_SCOREBOARD_ACTION_INC, child->wp->scoreboard);
199 FILE *slowlog;
200
201 zlog(ZLOG_NOTICE, "about to trace %d", (int) child->pid);
202
203 slowlog = fopen(child->wp->config->slowlog, "a+");
204
205 if (!slowlog) {
206 zlog(ZLOG_SYSERROR, "unable to open slowlog (%s)", child->wp->config->slowlog);
207 goto done0;
208 }
209
210 if (0 > fpm_trace_ready(child->pid)) {
211 goto done1;
212 }
213
214 if (0 > fpm_php_trace_dump(child, slowlog)) {
215 fprintf(slowlog, "+++ dump failed\n");
216 }
217
218 if (0 > fpm_trace_close(child->pid)) {
219 goto done1;
220 }
221
222 done1:
223 fclose(slowlog);
224
225 done0:
226 fpm_pctl_kill(child->pid, FPM_PCTL_CONT);
227 child->tracer = 0;
228
229 zlog(ZLOG_NOTICE, "finished trace of %d", (int) child->pid);
230 }
231 /* }}} */
232
233 #endif
234
