From 8dc967392829373c961d1869c6c0b28bf30cfb6f Mon Sep 17 00:00:00 2001 From: fyodor Date: Sat, 11 Aug 2007 05:13:16 +0000 Subject: [PATCH] merge soc07 r5085 - Changing bare printf()s to log_write(LOG_PLAIN,)s because these were always printed even when things like XML and greppable output were sent to stdout (e.g. -oX -). This also adds o.scriptTrace() to make --script-trace behave more like --packet-trace and --version-trace. Nsock tracing was done unconditionally in NSE, and that has been changed to only be done when o.scriptTrace() is true. --- NmapOps.h | 3 +++ nmap.cc | 14 ++++++------ nmap_rpc.cc | 37 +++++++++++++++--------------- nse_debug.cc | 21 +++++++++-------- nse_nsock.cc | 12 ++++++---- osscan.cc | 12 +++++----- osscan2.cc | 38 +++++++++++++++--------------- portlist.cc | 2 +- scan_engine.cc | 50 ++++++++++++++++++++-------------------- service_scan.cc | 26 ++++++++++----------- tcpip.cc | 61 ++++++++++++++++++++++++------------------------- timing.cc | 2 +- utils.cc | 36 ++++++++++++++--------------- 13 files changed, 160 insertions(+), 154 deletions(-) diff --git a/NmapOps.h b/NmapOps.h index f9258ba150..5f800e29c2 100644 --- a/NmapOps.h +++ b/NmapOps.h @@ -168,6 +168,9 @@ class NmapOps { int sendpref; bool packetTrace() { return (debugging >= 3)? true : pTrace; } bool versionTrace() { return packetTrace()? true : vTrace; } +#ifndef NOLUA + bool scriptTrace() { return packetTrace()? true : scripttrace; } +#endif // Note that packetTrace may turn on at high debug levels even if // setPacketTrace(false) has been called void setPacketTrace(bool pt) { pTrace = pt; } diff --git a/nmap.cc b/nmap.cc index 829ca988c9..4b9ece91bc 100644 --- a/nmap.cc +++ b/nmap.cc @@ -1446,13 +1446,13 @@ int nmap_main(int argc, char *argv[]) { // At this point we should fully know our timing parameters if (o.debugging) { - printf("--------------- Timing report ---------------\n"); - printf(" hostgroups: min %d, max %d\n", o.minHostGroupSz(), o.maxHostGroupSz()); - printf(" rtt-timeouts: init %d, min %d, max %d\n", o.initialRttTimeout(), o.minRttTimeout(), o.maxRttTimeout()); - printf(" max-scan-delay: TCP %d, UDP %d\n", o.maxTCPScanDelay(), o.maxUDPScanDelay()); - printf(" parallelism: min %d, max %d\n", o.min_parallelism, o.max_parallelism); - printf(" max-retries: %d, host-timeout: %ld\n", o.getMaxRetransmissions(), o.host_timeout); - printf("---------------------------------------------\n"); + log_write(LOG_PLAIN, "--------------- Timing report ---------------\n"); + log_write(LOG_PLAIN, " hostgroups: min %d, max %d\n", o.minHostGroupSz(), o.maxHostGroupSz()); + log_write(LOG_PLAIN, " rtt-timeouts: init %d, min %d, max %d\n", o.initialRttTimeout(), o.minRttTimeout(), o.maxRttTimeout()); + log_write(LOG_PLAIN, " max-scan-delay: TCP %d, UDP %d\n", o.maxTCPScanDelay(), o.maxUDPScanDelay()); + log_write(LOG_PLAIN, " parallelism: min %d, max %d\n", o.min_parallelism, o.max_parallelism); + log_write(LOG_PLAIN, " max-retries: %d, host-timeout: %ld\n", o.getMaxRetransmissions(), o.host_timeout); + log_write(LOG_PLAIN, "---------------------------------------------\n"); } /* Before we randomize the ports scanned, we must initialize PortList class. */ diff --git a/nmap_rpc.cc b/nmap_rpc.cc index 31e0c21ff3..b230bb8a6b 100644 --- a/nmap_rpc.cc +++ b/nmap_rpc.cc @@ -235,7 +235,7 @@ int send_rpc_query(const struct in_addr *target_host, unsigned short portno, rpc_xid_base = (unsigned long) get_random_uint(); if (o.debugging > 1) { - printf("Sending RPC probe for program %li to %hu/%s -- scan_offset=%d trynum=%d xid=%lX\n", program, portno, proto2ascii(ipproto), scan_offset, trynum, rpc_xid_base + ((portno & 0x3FFF) << 16) + (trynum << 30) + scan_offset); + log_write(LOG_PLAIN, "Sending RPC probe for program %li to %hu/%s -- scan_offset=%d trynum=%d xid=%lX\n", program, portno, proto2ascii(ipproto), scan_offset, trynum, rpc_xid_base + ((portno & 0x3FFF) << 16) + (trynum << 30) + scan_offset); } /* First we check whether we have to create a new connection -- we @@ -357,9 +357,9 @@ static int rpc_are_we_done(char *msg, int msg_len, Target *target, /* This is not a valid reply -- we kill the port (from an RPC perspective) */ if (o.debugging > 1) { - printf("Port %hu/%s labelled NON_RPC because of invalid sized message (%d)\n", - rsi->rpc_current_port->portno, - proto2ascii(rsi->rpc_current_port->proto, true), msg_len); + log_write(LOG_PLAIN, "Port %hu/%s labelled NON_RPC because of invalid sized message (%d)\n", + rsi->rpc_current_port->portno, + proto2ascii(rsi->rpc_current_port->proto, true), msg_len); } rsi->rpc_status = RPC_STATUS_NOT_RPC; ss->numqueries_outstanding = 0; @@ -372,7 +372,7 @@ static int rpc_are_we_done(char *msg, int msg_len, Target *target, if (((scan_offset >> 16) & 0x3FFF) != (unsigned long) (rsi->rpc_current_port->portno & 0x3FFF)) { /* Doh -- this doesn't seem right */ if (o.debugging > 1) { - printf("Port %hu/%s labelled NON_RPC because ((scan_offset >> 16) & 0x3FFF) is %li\n", rsi->rpc_current_port->portno, proto2ascii(rsi->rpc_current_port->proto, true), ((scan_offset >> 16) & 0x3FFF)); + log_write(LOG_PLAIN, "Port %hu/%s labelled NON_RPC because ((scan_offset >> 16) & 0x3FFF) is %li\n", rsi->rpc_current_port->portno, proto2ascii(rsi->rpc_current_port->proto, true), ((scan_offset >> 16) & 0x3FFF)); } rsi->rpc_status = RPC_STATUS_NOT_RPC; ss->numqueries_outstanding = 0; @@ -542,12 +542,12 @@ unsigned long current_msg_len; return; } if (o.debugging > 1) - printf("Received %d byte UDP packet\n", res); + log_write(LOG_PLAIN, "Received %d byte UDP packet\n", res); /* Now we check that the response is from the expected host/port */ if (from.sin_addr.s_addr != target->v4host().s_addr || from.sin_port != htons(rsi->rpc_current_port->portno)) { if (o.debugging > 1) { - printf("Received UDP packet from %d.%d.%d.%d/%hu when expecting packet from %d.%d.%d.%d/%hu\n", NIPQUAD(from.sin_addr.s_addr), ntohs(from.sin_port), NIPQUAD(target->v4host().s_addr), rsi->rpc_current_port->portno); + log_write(LOG_PLAIN, "Received UDP packet from %d.%d.%d.%d/%hu when expecting packet from %d.%d.%d.%d/%hu\n", NIPQUAD(from.sin_addr.s_addr), ntohs(from.sin_port), NIPQUAD(target->v4host().s_addr), rsi->rpc_current_port->portno); } continue; } @@ -578,10 +578,10 @@ unsigned long current_msg_len; /* This is suspiciously small -- I'm assuming this is not the first part of a valid RPC packet */ if (o.debugging > 1) { - printf("Port %hu/%s labelled NON_RPC because tcp_readlen is %d (should be at least 28)\n", - rsi->rpc_current_port->portno, - proto2ascii(rsi->rpc_current_port->proto, true), - (int) tcp_readlen); + log_write(LOG_PLAIN, "Port %hu/%s labelled NON_RPC because tcp_readlen is %d (should be at least 28)\n", + rsi->rpc_current_port->portno, + proto2ascii(rsi->rpc_current_port->proto, true), + (int) tcp_readlen); } ss->numqueries_outstanding = 0; rsi->rpc_status = RPC_STATUS_NOT_RPC; @@ -592,9 +592,10 @@ unsigned long current_msg_len; if (current_msg_len > tcp_readlen - 4) { if (o.debugging > 1) { - printf("Port %hu/%s labelled NON_RPC because current_msg_len is %li while tcp_readlen is %d\n", rsi->rpc_current_port->portno, - proto2ascii(rsi->rpc_current_port->proto, true), - current_msg_len, (int) tcp_readlen); + log_write(LOG_PLAIN, "Port %hu/%s labelled NON_RPC because current_msg_len is %li while tcp_readlen is %d\n", + rsi->rpc_current_port->portno, + proto2ascii(rsi->rpc_current_port->proto, true), + current_msg_len, (int) tcp_readlen); } ss->numqueries_outstanding = 0; rsi->rpc_status = RPC_STATUS_NOT_RPC; @@ -622,10 +623,10 @@ unsigned long current_msg_len; if (current_msg_len < 24 || current_msg_len > 32) { ss->numqueries_outstanding = 0; if (o.debugging > 1) { - printf("Port %hu/%s labelled NON_RPC because current_msg_len is %li\n", - rsi->rpc_current_port->portno, - proto2ascii(rsi->rpc_current_port->proto, true), - current_msg_len); + log_write(LOG_PLAIN, "Port %hu/%s labelled NON_RPC because current_msg_len is %li\n", + rsi->rpc_current_port->portno, + proto2ascii(rsi->rpc_current_port->proto, true), + current_msg_len); } rsi->rpc_status = RPC_STATUS_NOT_RPC; return; diff --git a/nse_debug.cc b/nse_debug.cc index a07e9cf395..1b22a09e9b 100644 --- a/nse_debug.cc +++ b/nse_debug.cc @@ -1,16 +1,17 @@ #include "nse_debug.h" +#include "output.h" void l_dumpStack(lua_State* l) { int stack_height = lua_gettop(l); int i; - printf("-== Stack Dump Begin ==-\n"); + log_write(LOG_PLAIN, "-== Stack Dump Begin ==-\n"); for(i = -1; i >= 0 - stack_height; i--) { - printf("%d: ", i); + log_write(LOG_PLAIN, "%d: ", i); l_dumpValue(l, i); } - printf("-== Stack Dump End ==-\n"); + log_write(LOG_PLAIN, "-== Stack Dump End ==-\n"); } void l_dumpValue(lua_State* l, int i) { @@ -20,19 +21,19 @@ void l_dumpValue(lua_State* l, int i) { l_dumpFunction(l, i); else if(lua_isstring(l, i)) { lua_pushvalue(l, i); - printf("string '%s'\n", lua_tostring(l, -1)); + log_write(LOG_PLAIN, "string '%s'\n", lua_tostring(l, -1)); lua_pop(l, 1); } else if(lua_isboolean(l, i)) - printf("boolean: %s", lua_toboolean(l, i) ? "true\n" : "false\n"); + log_write(LOG_PLAIN, "boolean: %s", lua_toboolean(l, i) ? "true\n" : "false\n"); else if(lua_isnumber(l, i)) - printf("number: %g\n", lua_tonumber(l, i)); + log_write(LOG_PLAIN, "number: %g\n", lua_tonumber(l, i)); else - printf("%s\n", lua_typename(l, lua_type(l, i))); + log_write(LOG_PLAIN, "%s\n", lua_typename(l, lua_type(l, i))); } void l_dumpTable(lua_State *l, int index) { - printf("table\n"); + log_write(LOG_PLAIN, "table\n"); lua_pushnil(l); if (index<0) --index; @@ -47,12 +48,12 @@ void l_dumpTable(lua_State *l, int index) { void l_dumpFunction(lua_State* l, int index) { // lua_Debug ar; - printf("function\n"); + log_write(LOG_PLAIN, "function\n"); // lua_pushvalue(l, index); // lua_getinfo(l, ">n", &ar); // -// printf("\tname: %s %s\n", ar.namewhat, ar.name); +// log_write(LOG_PLAIN, "\tname: %s %s\n", ar.namewhat, ar.name); fflush(stdout); } diff --git a/nse_nsock.cc b/nse_nsock.cc index 0a79f23277..9d72425dbb 100644 --- a/nse_nsock.cc +++ b/nse_nsock.cc @@ -76,7 +76,9 @@ int l_nsock_open(lua_State* l) { auxiliar_newclass(l, "nsock", l_nsock); nsp = nsp_new(NULL); - nsp_settrace(nsp, o.debugging, o.getStartTime()); + + if (o.scriptTrace()) + nsp_settrace(nsp, 5, o.getStartTime()); return NSOCK_WRAPPER_SUCCESS; } @@ -183,7 +185,7 @@ static int l_nsock_connect(lua_State* l) { void l_nsock_connect_handler(nsock_pool nsp, nsock_event nse, void *lua_state) { lua_State* l = (lua_State*) lua_state; - if(o.scripttrace) { + if(o.scriptTrace()) { l_nsock_trace(nse_iod(nse), "CONNECT", TO); } @@ -206,7 +208,7 @@ static int l_nsock_send(lua_State* l) { return 2; } - if(o.scripttrace) { + if(o.scriptTrace()) { hexified = nse_hexify((const void*)string, string_len); l_nsock_trace(udata->nsiod, hexified, TO); free(hexified); @@ -279,7 +281,7 @@ void l_nsock_receive_handler(nsock_pool nsp, nsock_event nse, void *lua_state) { if(l_nsock_checkstatus(l, nse) == NSOCK_WRAPPER_SUCCESS) { rcvd_string = nse_readbuf(nse, &rcvd_len); - if(o.scripttrace) { + if(o.scriptTrace()) { hexified = nse_hexify((const void*) rcvd_string, (size_t) rcvd_len); l_nsock_trace(nse_iod(nse), hexified, FROM); free(hexified); @@ -407,7 +409,7 @@ static int l_nsock_close(lua_State* l) { return 2; } - if(o.scripttrace) { + if(o.scriptTrace()) { l_nsock_trace(udata->nsiod, "CLOSE", TO); } diff --git a/osscan.cc b/osscan.cc index 4a68f1f81a..17cb714609 100644 --- a/osscan.cc +++ b/osscan.cc @@ -910,7 +910,7 @@ static FingerPrint *get_fingerprint(Target *target, struct seq_info *si) { } if (o.debugging) - printf("The avg TCP TS HZ is: %f\n", avg_ts_hz); + log_write(LOG_PLAIN, "The avg TCP TS HZ is: %f\n", avg_ts_hz); if (avg_ts_hz > 0 && avg_ts_hz < 3.9) { /* relatively wide range because sampling time so short and frequency so slow */ si->ts_seqclass = TS_SEQ_2HZ; @@ -1164,11 +1164,11 @@ static int compareclassifications(FingerPrint *referenceFP, } } else { if (verbose) - printf("Observed fingerprint lacks a classification\n"); + log_write(LOG_PLAIN, "Observed fingerprint lacks a classification\n"); return 1; } if (verbose) - printf("[WARN] Classification of observed fingerprint does not appear in reference fingerprint.\n"); + log_write(LOG_PLAIN, "[WARN] Classification of observed fingerprint does not appear in reference fingerprint.\n"); return 1; } @@ -1293,9 +1293,9 @@ static int AVal_match(struct AVal *reference, struct AVal *fprint, struct AVal * return 0; } if (verbose) - printf("%s.%s: \"%s\" NOMATCH \"%s\" (%d %s)\n", testGroupName, - current_ref->attribute, current_fp->value, - current_ref->value, pointsThisTest, (pointsThisTest == 1)? "point" : "points"); + log_write(LOG_PLAIN, "%s.%s: \"%s\" NOMATCH \"%s\" (%d %s)\n", testGroupName, + current_ref->attribute, current_fp->value, + current_ref->value, pointsThisTest, (pointsThisTest == 1)? "point" : "points"); } else subtests_succeeded += pointsThisTest; /* Whew, we made it past one Attribute alive , on to the next! */ } diff --git a/osscan2.cc b/osscan2.cc index ca4ac5a3dc..ef6a6aeb72 100644 --- a/osscan2.cc +++ b/osscan2.cc @@ -782,7 +782,7 @@ list::iterator HostOsScanStats::getActiveProbe(OFProbeType type, int if(probeI == probesActive.end()) { /* not found!? */ if(o.debugging > 1) - printf("Probe doesn't exist! Probe type: %d. Probe subid: %d\n", type, subid); + log_write(LOG_PLAIN, "Probe doesn't exist! Probe type: %d. Probe subid: %d\n", type, subid); return probesActive.end(); } @@ -811,8 +811,8 @@ double HostOsScanStats::timingRatio() { int msec_taken = TIMEVAL_MSEC_SUBTRACT(seq_send_times[NUM_SEQ_SAMPLES -1 ], seq_send_times[0]); if (o.debugging) { - printf("OS detection timingRatio() == (%.3f - %.3f) * 1000 / %d == %.3f\n", - seq_send_times[NUM_SEQ_SAMPLES - 1].tv_sec + seq_send_times[NUM_SEQ_SAMPLES - 1].tv_usec / 1000000.0, seq_send_times[0].tv_sec + (float) seq_send_times[0].tv_usec / 1000000.0, msec_ideal, (float) msec_taken / msec_ideal); + log_write(LOG_PLAIN, "OS detection timingRatio() == (%.3f - %.3f) * 1000 / %d == %.3f\n", + seq_send_times[NUM_SEQ_SAMPLES - 1].tv_sec + seq_send_times[NUM_SEQ_SAMPLES - 1].tv_usec / 1000000.0, seq_send_times[0].tv_sec + (float) seq_send_times[0].tv_usec / 1000000.0, msec_ideal, (float) msec_taken / msec_ideal); } return (double) msec_taken / msec_ideal; } @@ -1283,8 +1283,8 @@ void HostOsScan::sendNextProbe(HostOsScanStats *hss) { hss->moveProbeToActiveList(probeI); if (o.debugging > 1) { - printf("Send probe (type: %s, subid: %d) to %s\n", - probe->typestr(), probe->subid, hss->target->targetipstr()); + log_write(LOG_PLAIN, "Send probe (type: %s, subid: %d) to %s\n", + probe->typestr(), probe->subid, hss->target->targetipstr()); } } @@ -1521,8 +1521,8 @@ bool HostOsScan::processResp(HostOsScanStats *hss, struct ip *ip, unsigned int l adjust_times(hss, probe, rcvdtime); if(o.debugging > 1) - printf("Got a valid response for probe (type: %s subid: %d) from %s\n", - probe->typestr(), probe->subid, hss->target->targetipstr()); + log_write(LOG_PLAIN, "Got a valid response for probe (type: %s subid: %d) from %s\n", + probe->typestr(), probe->subid, hss->target->targetipstr()); /* delete the probe. */ hss->removeActiveProbe(probeI); @@ -3290,7 +3290,7 @@ static void begin_sniffer(HostOsScan *HOS, vector &Targets) { fatal("ran out of space in pcap filter"); filterlen = len; - if (o.debugging > 2) printf("Pcap filter: %s\n", pcap_filter); + if (o.debugging > 2) log_write(LOG_PLAIN, "Pcap filter: %s\n", pcap_filter); set_pcap_filter(Targets[0]->deviceName(), HOS->pd, pcap_filter); return; @@ -3347,7 +3347,7 @@ static void doSeqTests(OsScanInfo *OSI, HostOsScan *HOS) { do { if(timeToSleep > 0) { if(o.debugging > 1) { - printf("Sleep %dus for next sequence probe\n", timeToSleep); + log_write(LOG_PLAIN, "Sleep %dus for next sequence probe\n", timeToSleep); } usleep(timeToSleep); } @@ -3359,9 +3359,9 @@ static void doSeqTests(OsScanInfo *OSI, HostOsScan *HOS) { if(o.debugging > 2) { for(hostI = OSI->incompleteHosts.begin(); hostI != OSI->incompleteHosts.end(); hostI++) { hss = (*hostI)->hss; - printf("Host %s. ProbesToSend %d: \tProbesActive %d\n", - hss->target->targetipstr(), hss->numProbesToSend(), - hss->numProbesActive()); + log_write(LOG_PLAIN, "Host %s. ProbesToSend %d: \tProbesActive %d\n", + hss->target->targetipstr(), hss->numProbesToSend(), + hss->numProbesActive()); } } @@ -3416,7 +3416,7 @@ static void doSeqTests(OsScanInfo *OSI, HostOsScan *HOS) { if(to_usec < 2000) to_usec = 2000; if(o.debugging > 2) - printf("pcap wait time is %ld.\n", to_usec); + log_write(LOG_PLAIN, "pcap wait time is %ld.\n", to_usec); ip = (struct ip*) readip_pcap(HOS->pd, &bytes, to_usec, &rcvdtime, &linkhdr); @@ -3514,7 +3514,7 @@ static void doTUITests(OsScanInfo *OSI, HostOsScan *HOS) { if(timeToSleep > 0) { if(o.debugging > 1) { - printf("Time to sleep %d. Sleeping. \n", timeToSleep); + log_write(LOG_PLAIN, "Time to sleep %d. Sleeping. \n", timeToSleep); } usleep(timeToSleep); @@ -3528,9 +3528,9 @@ static void doTUITests(OsScanInfo *OSI, HostOsScan *HOS) { for(hostI = OSI->incompleteHosts.begin(); hostI != OSI->incompleteHosts.end(); hostI++) { hss = (*hostI)->hss; - printf("Host %s. ProbesToSend %d: \tProbesActive %d\n", - hss->target->targetipstr(), hss->numProbesToSend(), - hss->numProbesActive()); + log_write(LOG_PLAIN, "Host %s. ProbesToSend %d: \tProbesActive %d\n", + hss->target->targetipstr(), hss->numProbesToSend(), + hss->numProbesActive()); } } @@ -3585,7 +3585,7 @@ static void doTUITests(OsScanInfo *OSI, HostOsScan *HOS) { if(to_usec < 2000) to_usec = 2000; if(o.debugging > 2) - printf("pcap wait time is %ld.\n", to_usec); + log_write(LOG_PLAIN, "pcap wait time is %ld.\n", to_usec); ip = (struct ip*) readip_pcap(HOS->pd, &bytes, to_usec, &rcvdtime, &linkhdr); @@ -3849,7 +3849,7 @@ static int os_scan_2(vector &Targets) { if (!plural) { (*(OSI->incompleteHosts.begin()))->target->NameIP(targetstr, sizeof(targetstr)); } else snprintf(targetstr, sizeof(targetstr), "%d hosts", (int) OSI->numIncompleteHosts()); - printf("%s OS detection (try #%d) against %s\n", (itry == 0)? "Initiating" : "Retrying", itry + 1, targetstr); + log_write(LOG_PLAIN, "%s OS detection (try #%d) against %s\n", (itry == 0)? "Initiating" : "Retrying", itry + 1, targetstr); log_flush_all(); } startRound(OSI, HOS, itry); diff --git a/portlist.cc b/portlist.cc index 84377d155e..01c3510f7a 100644 --- a/portlist.cc +++ b/portlist.cc @@ -455,7 +455,7 @@ int PortList::addPort(u16 portno, u8 protocol, char *owner, int state) { int PortList::removePort(u16 portno, u8 protocol) { Port *answer = NULL; - printf("Removed %d\n", portno); + log_write(LOG_PLAIN, "Removed %d\n", portno); answer = getPortEntry(portno, protocol); if (!answer) diff --git a/scan_engine.cc b/scan_engine.cc index 8aeae3d7b4..e3686b9a8c 100644 --- a/scan_engine.cc +++ b/scan_engine.cc @@ -1514,7 +1514,7 @@ static void ultrascan_adjust_times(UltraScanInfo *USI, HostScanStats *hss, if (probe->tryno > 0 || !rcvdtime) { /* A previous probe must have been lost ... */ if (o.debugging > 1) - printf("Ultrascan DROPPED %sprobe packet to %s detected\n", probe->isPing()? "PING " : "", hss->target->targetipstr()); + log_write(LOG_PLAIN, "Ultrascan DROPPED %sprobe packet to %s detected\n", probe->isPing()? "PING " : "", hss->target->targetipstr()); // Drops often come in big batches, but we only want one decrease per batch. if (TIMEVAL_SUBTRACT(probe->sent, hss->timing.last_drop) > 0) { hss->timing.cwnd = USI->perf.low_cwnd; @@ -1573,9 +1573,9 @@ static void ultrascan_adjust_times(UltraScanInfo *USI, HostScanStats *hss, unsigned int olddelay = hss->sdn.delayms; hss->boostScanDelay(); if (o.verbose && hss->sdn.delayms != olddelay) - printf("Increasing send delay for %s from %d to %d due to %d out of %d dropped probes since last increase.\n", - hss->target->targetipstr(), olddelay, hss->sdn.delayms, oldbad, - oldbad + oldgood); + log_write(LOG_PLAIN, "Increasing send delay for %s from %d to %d due to %d out of %d dropped probes since last increase.\n", + hss->target->targetipstr(), olddelay, hss->sdn.delayms, oldbad, + oldbad + oldgood); } } @@ -1750,7 +1750,7 @@ static bool ultrascan_port_pspec_update(UltraScanInfo *USI, if (swappingport) { if (o.debugging > 1) - printf("Changing ping technique for %s to %s\n", hss->target->targetipstr(), pspectype2ascii(pspec->type)); + log_write(LOG_PLAIN, "Changing ping technique for %s to %s\n", hss->target->targetipstr(), pspectype2ascii(pspec->type)); hss->pingprobe = *pspec; hss->pingprobestate = newstate; } @@ -2310,8 +2310,8 @@ static void doAnyRetryStackRetransmits(UltraScanInfo *USI) { static void sendPingProbe(UltraScanInfo *USI, HostScanStats *hss) { if (o.debugging > 1) { char tmpbuf[32]; - printf("Ultrascan PING SENT to %s [%s]\n", hss->target->targetipstr(), - probespec2ascii(&hss->pingprobe, tmpbuf, sizeof(tmpbuf))); + log_write(LOG_PLAIN, "Ultrascan PING SENT to %s [%s]\n", hss->target->targetipstr(), + probespec2ascii(&hss->pingprobe, tmpbuf, sizeof(tmpbuf))); } if (USI->scantype == CONNECT_SCAN) { sendConnectScanProbe(USI, hss, hss->pingprobe.pd.tcp.dport, 0, @@ -2452,25 +2452,25 @@ static void printAnyStats(UltraScanInfo *USI) { /* Print debugging states for each host being scanned */ if (o.debugging > 2) { - printf("**TIMING STATS**: IP, probes active/freshportsleft/retry_stack/outstanding/retranwait/onbench, cwnd/ccthresh/delay, timeout/srtt/rttvar/\n"); - printf(" Groupstats (%d/%d incomplete): %d/*/*/*/*/* %.2f/%d/* %d/%d/%d\n", - USI->numIncompleteHosts(), USI->numInitialHosts(), - USI->gstats->num_probes_active, USI->gstats->timing.cwnd, - USI->gstats->timing.ccthresh, USI->gstats->to.timeout, - USI->gstats->to.srtt, USI->gstats->to.rttvar); + log_write(LOG_PLAIN, "**TIMING STATS**: IP, probes active/freshportsleft/retry_stack/outstanding/retranwait/onbench, cwnd/ccthresh/delay, timeout/srtt/rttvar/\n"); + log_write(LOG_PLAIN, " Groupstats (%d/%d incomplete): %d/*/*/*/*/* %.2f/%d/* %d/%d/%d\n", + USI->numIncompleteHosts(), USI->numInitialHosts(), + USI->gstats->num_probes_active, USI->gstats->timing.cwnd, + USI->gstats->timing.ccthresh, USI->gstats->to.timeout, + USI->gstats->to.srtt, USI->gstats->to.rttvar); for(hostI = USI->incompleteHosts.begin(); hostI != USI->incompleteHosts.end(); hostI++) { hss = *hostI; hss->getTiming(&hosttm); - printf(" %s: %d/%d/%d/%d/%d/%d %.2f/%d/%d %li/%d/%d\n", hss->target->targetipstr(), - hss->num_probes_active, hss->freshPortsLeft(), - (int) hss->retry_stack.size(), - hss->num_probes_outstanding(), - hss->num_probes_waiting_retransmit, (int) hss->probe_bench.size(), - hosttm.cwnd, hosttm.ccthresh, hss->sdn.delayms, - hss->probeTimeout(), hss->target->to.srtt, - hss->target->to.rttvar); + log_write(LOG_PLAIN, " %s: %d/%d/%d/%d/%d/%d %.2f/%d/%d %li/%d/%d\n", hss->target->targetipstr(), + hss->num_probes_active, hss->freshPortsLeft(), + (int) hss->retry_stack.size(), + hss->num_probes_outstanding(), + hss->num_probes_waiting_retransmit, (int) hss->probe_bench.size(), + hosttm.cwnd, hosttm.ccthresh, hss->sdn.delayms, + hss->probeTimeout(), hss->target->to.srtt, + hss->target->to.rttvar); } } @@ -2959,7 +2959,7 @@ static bool get_pcap_result(UltraScanInfo *USI, struct timeval *stime) { be used in those cases where it happens. Then I should make this just a debugging > X statement. */ if (o.debugging) - printf("Bad Sequence number from host %s.\n", inet_ntoa(ip->ip_src)); + log_write(LOG_PLAIN, "Bad Sequence number from host %s.\n", inet_ntoa(ip->ip_src)); /* I'll just assume it is a response to this (most recent) probe. */ if (probe->isPing()) { pingseq = probe->pingseq; @@ -3305,7 +3305,7 @@ static void begin_sniffer(UltraScanInfo *USI, vector &Targets) { fatal("ran out of space in pcap filter"); filterlen = len; } else assert(0); /* Other scan types? */ - if (o.debugging > 2) printf("Pcap filter: %s\n", pcap_filter); + if (o.debugging > 2) log_write(LOG_PLAIN, "Pcap filter: %s\n", pcap_filter); set_pcap_filter(Targets[0]->deviceName(), USI->pd, pcap_filter); /* pcap_setnonblock(USI->pd, 1, NULL); */ @@ -3386,7 +3386,7 @@ static void processData(UltraScanInfo *USI) { if (tryno_capped && lastRetryCappedWarning != USI) { /* Perhaps I should give this on a per-host basis. Oh well, hopefully it is rare anyway. */ - printf("Warning: Giving up on port early because retransmission cap hit.\n"); + log_write(LOG_PLAIN, "Warning: Giving up on port early because retransmission cap hit.\n"); lastRetryCappedWarning = USI; } continue; @@ -3415,7 +3415,7 @@ static void processData(UltraScanInfo *USI) { long tv_diff; gettimeofday(&USI->now, NULL); tv_diff = TIMEVAL_MSEC_SUBTRACT(USI->now, tv_start); - if (tv_diff > 30) printf("%s took %lims\n", __func__, tv_diff); + if (tv_diff > 30) log_write(LOG_PLAIN, "%s took %lims\n", __func__, tv_diff); } } diff --git a/service_scan.cc b/service_scan.cc index 56858ac699..bce1163bb8 100644 --- a/service_scan.cc +++ b/service_scan.cc @@ -1949,7 +1949,7 @@ static int launchSomeServiceProbes(nsock_pool nsp, ServiceGroup *SG) { if (nextprobe == NULL) { if (warn_no_scanning && o.debugging) { - printf("Service scan: Not probing some ports due to low intensity\n"); + log_write(LOG_PLAIN, "Service scan: Not probing some ports due to low intensity\n"); warn_no_scanning=0; } end_svcprobe(nsp, PROBESTATE_FINISHED_NOMATCH, SG, svc, NULL); @@ -1961,7 +1961,7 @@ static int launchSomeServiceProbes(nsock_pool nsp, ServiceGroup *SG) { fatal("Failed to allocate Nsock I/O descriptor in %s()", __func__); } if (o.debugging > 1) { - printf("Starting probes against new service: %s:%hi (%s)\n", svc->target->targetipstr(), svc->portno, proto2ascii(svc->proto)); + log_write(LOG_PLAIN, "Starting probes against new service: %s:%hi (%s)\n", svc->target->targetipstr(), svc->portno, proto2ascii(svc->proto)); } svc->target->TargetSockAddr(&ss, &ss_len); if (svc->proto == IPPROTO_TCP) @@ -2134,16 +2134,16 @@ static void servicescan_read_handler(nsock_pool nsp, nsock_event nse, void *myda } else { if (o.debugging > 1) if (MD->product || MD->version || MD->info) - printf("Service scan match (Probe %s matched with %s): %s:%hi is %s%s. Version: |%s|%s|%s|\n", - probe->getName(), (*probe->fallbacks[fallbackDepth]).getName(), - svc->target->NameIP(), svc->portno, (svc->tunnel == SERVICE_TUNNEL_SSL)? "SSL/" : "", - MD->serviceName, (MD->product)? MD->product : "", (MD->version)? MD->version : "", - (MD->info)? MD->info : ""); + log_write(LOG_PLAIN, "Service scan match (Probe %s matched with %s): %s:%hi is %s%s. Version: |%s|%s|%s|\n", + probe->getName(), (*probe->fallbacks[fallbackDepth]).getName(), + svc->target->NameIP(), svc->portno, (svc->tunnel == SERVICE_TUNNEL_SSL)? "SSL/" : "", + MD->serviceName, (MD->product)? MD->product : "", (MD->version)? MD->version : "", + (MD->info)? MD->info : ""); else - printf("Service scan %s match (Probe %s matched with %s): %s:%hi is %s%s\n", - (MD->isSoft)? "soft" : "hard", - probe->getName(), (*probe->fallbacks[fallbackDepth]).getName(), - svc->target->NameIP(), svc->portno, (svc->tunnel == SERVICE_TUNNEL_SSL)? "SSL/" : "", MD->serviceName); + log_write(LOG_PLAIN, "Service scan %s match (Probe %s matched with %s): %s:%hi is %s%s\n", + (MD->isSoft)? "soft" : "hard", + probe->getName(), (*probe->fallbacks[fallbackDepth]).getName(), + svc->target->NameIP(), svc->portno, (svc->tunnel == SERVICE_TUNNEL_SSL)? "SSL/" : "", MD->serviceName); svc->probe_matched = MD->serviceName; if (MD->product) Strncpy(svc->product_matched, MD->product, sizeof(svc->product_matched)); @@ -2337,7 +2337,7 @@ static void remove_excluded_ports(AllProbes *AP, ServiceGroup *SG) { svc = *i; if (AP->isExcluded(svc->portno, svc->proto)) { - if (o.debugging) printf("EXCLUDING %d/%s\n", svc->portno, svc->proto==IPPROTO_TCP ? "tcp" : "udp"); + if (o.debugging) log_write(LOG_PLAIN, "EXCLUDING %d/%s\n", svc->portno, svc->proto==IPPROTO_TCP ? "tcp" : "udp"); svc->port->setServiceProbeResults(PROBESTATE_EXCLUDED, NULL, SERVICE_TUNNEL_NONE, @@ -2375,7 +2375,7 @@ int service_scan(vector &Targets) { SG = new ServiceGroup(Targets, AP); if (o.override_excludeports) { - if (o.debugging || o.verbose) printf("Overriding exclude ports option! Some undesirable ports may be version scanned!\n"); + if (o.debugging || o.verbose) log_write(LOG_PLAIN, "Overriding exclude ports option! Some undesirable ports may be version scanned!\n"); } else { remove_excluded_ports(AP, SG); } diff --git a/tcpip.cc b/tcpip.cc index 546db422f7..dc7a11d9d9 100644 --- a/tcpip.cc +++ b/tcpip.cc @@ -1565,36 +1565,35 @@ strncpy(sourcehost, inet_ntoa(bullshit), 16); i = 4 * (ntohs(ip->ip_hl) + ntohs(tcp->th_off)); if (ip->ip_p== IPPROTO_TCP) { if (realfrag) - printf("Packet is fragmented, offset field: %u\n", realfrag); + log_write(LOG_PLAIN, "Packet is fragmented, offset field: %u\n", realfrag); else { - printf("TCP packet: %s:%d -> %s:%d (total: %d bytes)\n", sourcehost, - ntohs(tcp->th_sport), inet_ntoa(bullshit2), - ntohs(tcp->th_dport), tot_len); - printf("Flags: "); - if (!tcp->th_flags) printf("(none)"); - if (tcp->th_flags & TH_RST) printf("RST "); - if (tcp->th_flags & TH_SYN) printf("SYN "); - if (tcp->th_flags & TH_ACK) printf("ACK "); - if (tcp->th_flags & TH_PUSH) printf("PSH "); - if (tcp->th_flags & TH_FIN) printf("FIN "); - if (tcp->th_flags & TH_URG) printf("URG "); - printf("\n"); - - printf("ipid: %hu ttl: %hu ", ntohs(ip->ip_id), ip->ip_ttl); - - if (tcp->th_flags & (TH_SYN | TH_ACK)) printf("Seq: %u\tAck: %u\n", - (unsigned int) ntohl(tcp->th_seq), (unsigned int) ntohl(tcp->th_ack)); - else if (tcp->th_flags & TH_SYN) printf("Seq: %u\n", (unsigned int) ntohl(tcp->th_seq)); - else if (tcp->th_flags & TH_ACK) printf("Ack: %u\n", (unsigned int) ntohl(tcp->th_ack)); + log_write(LOG_PLAIN, "TCP packet: %s:%d -> %s:%d (total: %d bytes)\n", sourcehost, + ntohs(tcp->th_sport), inet_ntoa(bullshit2), + ntohs(tcp->th_dport), tot_len); + log_write(LOG_PLAIN, "Flags: "); + if (!tcp->th_flags) log_write(LOG_PLAIN, "(none)"); + if (tcp->th_flags & TH_RST) log_write(LOG_PLAIN, "RST "); + if (tcp->th_flags & TH_SYN) log_write(LOG_PLAIN, "SYN "); + if (tcp->th_flags & TH_ACK) log_write(LOG_PLAIN, "ACK "); + if (tcp->th_flags & TH_PUSH) log_write(LOG_PLAIN, "PSH "); + if (tcp->th_flags & TH_FIN) log_write(LOG_PLAIN, "FIN "); + if (tcp->th_flags & TH_URG) log_write(LOG_PLAIN, "URG "); + log_write(LOG_PLAIN, "\n"); + + log_write(LOG_PLAIN, "ipid: %hu ttl: %hu ", ntohs(ip->ip_id), ip->ip_ttl); + + if (tcp->th_flags & (TH_SYN | TH_ACK)) log_write(LOG_PLAIN, "Seq: %u\tAck: %u\n", (unsigned int) ntohl(tcp->th_seq), (unsigned int) ntohl(tcp->th_ack)); + else if (tcp->th_flags & TH_SYN) log_write(LOG_PLAIN, "Seq: %u\n", (unsigned int) ntohl(tcp->th_seq)); + else if (tcp->th_flags & TH_ACK) log_write(LOG_PLAIN, "Ack: %u\n", (unsigned int) ntohl(tcp->th_ack)); } } if (readdata && i < tot_len) { - printf("Data portion:\n"); + log_write(LOG_PLAIN, "Data portion:\n"); while(i < tot_len) { - printf("%2X%c", data[i], ((i+1) %16)? ' ' : '\n'); + log_write(LOG_PLAIN, "%2X%c", data[i], ((i+1) %16)? ' ' : '\n'); i++; } - printf("\n"); + log_write(LOG_PLAIN, "\n"); } return 0; } @@ -1625,22 +1624,22 @@ strncpy(sourcehost, inet_ntoa(bullshit), 16); i = 4 * (ntohs(ip->ip_hl)) + 8; if (ip->ip_p== IPPROTO_UDP) { if (realfrag) - printf("Packet is fragmented, offset field: %u\n", realfrag); + log_write(LOG_PLAIN, "Packet is fragmented, offset field: %u\n", realfrag); else { - printf("UDP packet: %s:%d -> %s:%d (total: %d bytes)\n", sourcehost, - ntohs(udp->uh_sport), inet_ntoa(bullshit2), - ntohs(udp->uh_dport), tot_len); + log_write(LOG_PLAIN, "UDP packet: %s:%d -> %s:%d (total: %d bytes)\n", sourcehost, + ntohs(udp->uh_sport), inet_ntoa(bullshit2), + ntohs(udp->uh_dport), tot_len); - printf("ttl: %hu ", ip->ip_ttl); + log_write(LOG_PLAIN, "ttl: %hu ", ip->ip_ttl); } } if (readdata && i < tot_len) { - printf("Data portion:\n"); + log_write(LOG_PLAIN, "Data portion:\n"); while(i < tot_len) { - printf("%2X%c", data[i], ((i+1)%16)? ' ' : '\n'); + log_write(LOG_PLAIN, "%2X%c", data[i], ((i+1)%16)? ' ' : '\n'); i++; } - printf("\n"); + log_write(LOG_PLAIN, "\n"); } return 0; } diff --git a/timing.cc b/timing.cc index df299d957f..6331b7c76e 100644 --- a/timing.cc +++ b/timing.cc @@ -225,7 +225,7 @@ void enforce_scan_delay(struct timeval *tv) { time_diff = TIMEVAL_MSEC_SUBTRACT(now, lastcall); if (time_diff < (int) o.scan_delay) { if (o.debugging > 1) { - printf("Sleeping for %d milliseconds in %s()\n", o.scan_delay - time_diff, __func__); + log_write(LOG_PLAIN, "Sleeping for %d milliseconds in %s()\n", o.scan_delay - time_diff, __func__); } usleep((o.scan_delay - time_diff) * 1000); gettimeofday(&lastcall, NULL); diff --git a/utils.cc b/utils.cc index 1d97b6119b..6b5ca65af3 100644 --- a/utils.cc +++ b/utils.cc @@ -152,17 +152,17 @@ int wildtest(char *wild, char *test) { void hdump(unsigned char *packet, unsigned int len) { unsigned int i=0, j=0; -printf("Here it is:\n"); +log_write(LOG_PLAIN, "Here it is:\n"); for(i=0; i < len; i++){ j = (unsigned) (packet[i]); - printf("%-2X ", j); + log_write(LOG_PLAIN, "%-2X ", j); if (!((i+1)%16)) - printf("\n"); + log_write(LOG_PLAIN, "\n"); else if (!((i+1)%4)) - printf(" "); + log_write(LOG_PLAIN, " "); } -printf("\n"); +log_write(LOG_PLAIN, "\n"); } /* A better version of hdump, from Lamont Granquist. Modified slightly @@ -180,7 +180,7 @@ void lamont_hdump(char *cp, unsigned int length) { int nshorts, nshorts2; int padding; - printf("\n\t"); + log_write(LOG_PLAIN, "\n\t"); padding = 0; sp = (u_short *)bp; ap = (u_char *)bp; @@ -190,44 +190,44 @@ void lamont_hdump(char *cp, unsigned int length) { j = 0; while(1) { while (--nshorts >= 0) { - printf(" %04x", ntohs(*sp)); + log_write(LOG_PLAIN, " %04x", ntohs(*sp)); sp++; if ((++i % 8) == 0) break; } if (nshorts < 0) { if ((length & 1) && (((i-1) % 8) != 0)) { - printf(" %02x ", *(u_char *)sp); + log_write(LOG_PLAIN, " %02x ", *(u_char *)sp); padding++; } nshorts = (8 - (nshorts2 - nshorts)); while(--nshorts >= 0) { - printf(" "); + log_write(LOG_PLAIN, " "); } - if (!padding) printf(" "); + if (!padding) log_write(LOG_PLAIN, " "); } - printf(" "); + log_write(LOG_PLAIN, " "); while (--nshorts2 >= 0) { - printf("%c%c", asciify[*ap], asciify[*(ap+1)]); + log_write(LOG_PLAIN, "%c%c", asciify[*ap], asciify[*(ap+1)]); ap += 2; if ((++j % 8) == 0) { - printf("\n\t"); + log_write(LOG_PLAIN, "\n\t"); break; } } if (nshorts2 < 0) { if ((length & 1) && (((j-1) % 8) != 0)) { - printf("%c", asciify[*ap]); + log_write(LOG_PLAIN, "%c", asciify[*ap]); } break; } } if ((length & 1) && (((i-1) % 8) == 0)) { - printf(" %02x", *(u_char *)sp); - printf(" %c", asciify[*ap]); + log_write(LOG_PLAIN, " %02x", *(u_char *)sp); + log_write(LOG_PLAIN, " %c", asciify[*ap]); } - printf("\n"); + log_write(LOG_PLAIN, "\n"); } #ifndef HAVE_STRERROR @@ -1059,7 +1059,7 @@ char *mmapfile(char *fname, int *length, int openflags) CloseHandle (fd); if (o.debugging > 2) - printf ("%s(): fd %08lX, gmap %08lX, fileptr %08lX, length %d\n", + log_write(LOG_PLAIN, "%s(): fd %08lX, gmap %08lX, fileptr %08lX, length %d\n", __func__, (DWORD)fd, (DWORD)gmap, (DWORD)fileptr, *length); return fileptr;