Hi!
I'm having problems with printing with Samba 2.2.5 and WinXP. I have samba
setup as a PDC and have 3 printers: HP LaserJet 5000N, HP LaserJet 8550DN
and HP DesignJet 1055CM. I used WinXP to upload the drivers for the
printers to XP clients and to 98 clients, and all went fine. I downloaded
the lastest PCL6 drivers for the Laserjet printers and the HPGL2/RTL
driver for the Designjet.
I can connect to the printers, view properties, print, cancel and resume
jobs. The problem is that the print queues on XP never refresh, and I
always have to hit F5 to refresh the queues manually after I print, cancel
or resume a job. In the logs I always get an
"srv_spoolss_receive_message: got incorrect message size (14)!" error
after printing, canceling or resuming jobs.
I already deleted nt*.tdb and started all over but the error persists.
I had the same problem with 2.2.3a and 2.2.4.
***********************************
Level 6 log follows:
[2002/06/21 13:31:01, 3] smbd/ipc.c:api_fd_reply(296)
Got API command 0x26 on pipe "spoolss" (pnum 7116)write_to_pipe:
7116
name: sp
oolss open: Yes len: 56
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_debug(60)
000000 smb_io_rpc_hdr
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0000 major : 05
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0001 minor : 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0002 pkt_type : 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0003 flags : 03
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0004 pack_type0: 10
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0005 pack_type1: 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0006 pack_type2: 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0007 pack_type3: 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
0008 frag_len : 0038
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
000a auth_len : 0000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
000c call_id : 00005d15
[2002/06/21 13:31:01, 5]
rpc_server/srv_pipe_hnd.c:unmarshall_rpc_header(391)
unmarshall_rpc_header: using little-endian RPC
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_debug(60)
000000 smb_io_rpc_hdr_req req
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
0000 alloc_hint: 00000020
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
0004 context_id: 0000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
0006 opnum : 0002
[2002/06/21 13:31:01, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(448)
free_pipe_context: destroying talloc pool of size 0
[2002/06/21 13:31:01, 3] rpc_server/srv_pipe.c:api_pipe_request(1148)
Doing \PIPE\spoolss
[2002/06/21 13:31:01, 4] rpc_server/srv_pipe.c:api_rpcTNP(1173)
api_rpcTNP: api_spoolss_rpc op 0x2 - api_rpcTNP: pipe 28950 rpc
command: SPOOL
SS_SETJOB
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_debug(60)
000000 spoolss_io_q_setjob
[2002/06/21 13:31:01, 6] rpc_parse/parse_prs.c:prs_debug(60)
000000 smb_io_pol_hnd printer handle
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
0000 data1: 00000000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
0004 data2: 00000067
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
0008 data3: 0000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
000a data4: 0000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8s(645)
000c data5: 63 1c 13 3d 66 0b 00 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
0014 jobid: 000000f8
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
0018 level: 00000000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
001c command: 00000005
[2002/06/21 13:31:01, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(16
8)
Found policy hnd[0] [000] 00 00 00 00 67 00 00 00 00 00 00 00 63 1C 13
3D ..
..g... ....c..[2002/06/21 13:31:01, 4] lib/util.c:dump_data(1537)
[010] 66 0B 00 00 f...
[2002/06/21 13:31:01, 4] rpc_server/srv_spoolss_nt.c:get_printer_snum(362)
short name:preto
[2002/06/21 13:31:01, 3] printing/print_generic.c:print_run_command(88)
Running the command `/usr/bin/lprm -Ppreto 183' gave 0
[2002/06/21 13:31:01, 3] printing/print_generic.c:print_run_command(88)
Running the command `/usr/bin/lpq -Ppreto' gave 0
[2002/06/21 13:31:01, 3] printing/printing.c:print_queue_update(416)
5 jobs in queue for preto
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_debug(60)
000000 spoolss_io_r_setjob
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_werror(617)
0000 status: WERR_OK
[2002/06/21 13:31:01, 5] rpc_server/srv_pipe.c:api_rpcTNP(1218)
api_rpcTNP: called api_spoolss_rpc successfully
[2002/06/21 13:31:01, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(448)
free_pipe_context: destroying talloc pool of size 0
[2002/06/21 13:31:01, 6] rpc_server/srv_pipe_hnd.c:read_from_pipe(803)
read_from_pipe: 7116 name: spoolss len: 5680
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_debug(60)
000000 smb_io_rpc_hdr hdr
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0000 major : 05
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0001 minor : 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0002 pkt_type : 02
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0003 flags : 03
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0004 pack_type0: 10
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0005 pack_type1: 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0006 pack_type2: 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0007 pack_type3: 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
0008 frag_len : 001c
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
000a auth_len : 0000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
000c call_id : 00005d15
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_debug(60)
000010 smb_io_rpc_hdr_resp resp
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
0010 alloc_hint: 00000004
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
0014 context_id: 0000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0016 cancel_ct : 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
0017 reserved : 00
[2002/06/21 13:31:01, 5] smbd/ipc.c:copy_trans_params_and_data(62)
copy_trans_params_and_data: params[0..0] data[0..28]
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(268)
size=84
smb_com=0x25
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=1
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(276)
smb_tid=1
smb_pid=1092
smb_uid=100
smb_mid=32832
smt_wct=10
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
smb_vwv[0]=0 (0x0)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
smb_vwv[1]=28 (0x1C)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
smb_vwv[2]=0 (0x0)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
smb_vwv[3]=0 (0x0)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
smb_vwv[4]=56 (0x38)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
smb_vwv[5]=0 (0x0)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
smb_vwv[6]=28 (0x1C)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
smb_vwv[7]=56 (0x38)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
smb_vwv[8]=0 (0x0)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
smb_vwv[9]=0 (0x0)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(291)
smb_bcc=29
[2002/06/21 13:31:01, 6] lib/util_sock.c:write_socket(518)
write_socket(12,88)
[2002/06/21 13:31:01, 6] lib/util_sock.c:write_socket(521)
write_socket(12,88) wrote 88
[2002/06/21 13:31:01, 2]
rpc_server/srv_spoolss_nt.c:srv_spoolss_receive_message (730)
srv_spoolss_receive_message: got incorrect message size (14)!
[2002/06/21 13:31:01, 5] smbd/oplock.c:receive_local_message(108)
receive_local_message: doing select with timeout of 1 ms
[2002/06/21 13:31:04, 6] smbd/process.c:process_smb(876)
Thank you for your help
Nuno Beirao